On Fri, 2005-11-04 at 09:19 -0800, Mark Womack wrote:
> 
> 
> I would much rather get on with 1.3 and do it the right way there.  

I'd rather we think of something better for 1.3 than waste time spinning
on this problem for 1.2.

You may be able to change every class in log4j to have more fine grained
locking semantics, but then you've possibly broken many classes that
have sub classed the appender.  For 1.3, it may be more prudent to add a
separate series of "concurrent" appenders.

Anyway, to further the discussion, I have examples of what a fine-locked
class may look like.  (These are newer than what's in Bugzilla.)
/*
 * Copyright 1999,2004 The Apache Software Foundation.
 * 
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 * 
 *      http://www.apache.org/licenses/LICENSE-2.0
 * 
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */

package org.apache.log4j.concurrent;

import org.apache.log4j.Layout;
import org.apache.log4j.Appender;
import org.apache.log4j.Level;
import org.apache.log4j.helpers.ReaderWriterLock;
import org.apache.log4j.spi.ComponentBase;
import org.apache.log4j.spi.Filter;
import org.apache.log4j.spi.LoggingEvent;
import org.apache.log4j.spi.OptionHandler;

/**
 * Base class for appenders that can benefit from a concurrency strategy.
 * Classes derived from this appender may have the [EMAIL PROTECTED] #append} method
 * called by multiple threads.  Derived classes must use internal locking to
 * prevent race conditions.
 * Derived classes must also override [EMAIL PROTECTED] #internalClose}.
 * <p>
 * Locking strategy:  Internally, there is a read-write lock to handle
 * concurrent modification.  A <i>write</i> lock is obtained to change states
 * (including before [EMAIL PROTECTED] #close}.)  A <i>read</i> lock is obtained to read
 * options.  Subclasses interested in state may check state using a public
 * method or within their own [EMAIL PROTECTED] #append} method.
 * </p>
 * @see #getWriteLock
 */
public abstract class ConcurrentAppender 
  extends ComponentBase implements Appender, OptionHandler
{
  
  /**
   * The layout variable does not need to be set if the appender
   * implementation has its own layout.
   */
  private Layout layout;

  /**
   * Appenders are named.
   */
  protected String name;

  /**
   * There is no level threshold filtering by default.
   * Should this be volatile?
   */
  private Level threshold;

  /**
   * Internal class, internally locked.
   */
  private FilterChain filter = new FilterChain();

  /**
   * Is this appender closed?
   */
  private SynchronizedBoolean closed = new SynchronizedBoolean(false);

  /**
   * Set to true when the appender is activated.
   * Subclasses can set this to false to indicate things are not in order.
   */
  protected SynchronizedBoolean active = new SynchronizedBoolean(false);
  
  /**
   * The guard prevents an appender from repeatedly calling its own doAppend
   * method.
   */
  private ThreadLocal guard = new ThreadLocal();

  /**
   * Write obtained to change the options, Read obtained to
   * append event.
   */
  private ReaderWriterLock lock = new ReaderWriterLock();


  /**
   * Constructs an AppenderSkeleton.
   *
   * @param isActive true if appender is ready for use upon construction.
   */
  protected ConcurrentAppender(final boolean isActive) {
    active.set(isActive);
  }

  /**
   * Derived appenders should override this method if option structure
   * requires it.
   * By default, sets [EMAIL PROTECTED] #active} to true.
   */
  public void activate() {
    active.set(true);
  }

  /**
   * Indicates if the appender is active.
   * By default, returns true if [EMAIL PROTECTED] #active.get()} is true and [EMAIL PROTECTED]
   * closed.get()} is false.
   */
  public boolean isActive() {
    return active.get() && !closed.get();
  }

  /**
   * Add a filter to end of the filter list.
   */
  public void addFilter(Filter newFilter) {
    filter.addFilter(newFilter);
  }

  /**
   * Clear the filters chain.
   */
  public void clearFilters() {
    filter.clear();
  }

  /**
   * Returns the head Filter.
   */
  public Filter getFilter() {
    return filter.getHead();
  }

  /**
   * Returns the layout of this appender. The value may be null.
   */
  public Layout getLayout() {
    return this.layout;
  }

  /**
   * Returns the name of this FileAppender.
   */
  public final String getName() {
    return this.name;
  }

  /**
   * Returns this appenders threshold level. See the [EMAIL PROTECTED] #setThreshold}
   * method for the meaning of this option.
   */
  public Level getThreshold() {
    return threshold;
  }

  /**
   * Check whether the message level is below the appender's threshold. If
   * there is no threshold set, then the return value is always
   * <code>true</code>.
   */
  public boolean isAsSevereAsThreshold(Level level) {
    Level copy = threshold;
    return ((copy == null) || copy.isGreaterOrEqual(level));
  }

  /**
   * This method performs threshold checks and invokes filters before
   * delegating actual logging to the subclasses specific [EMAIL PROTECTED] #append}
   * method.
   */
  public final void doAppend(LoggingEvent event) {

    if (!isAsSevereAsThreshold(event.getLevel()))
      return;

    if (!filter.accept(event))
      return;

    try {

      // Prevent concurrent re-entry
      // (There might be a cheaper way to do this)
      if (guard.get() != null)
        return;
      guard.set(this); // arbitrary lock

      lock.getReadLock();
      try {


        if (closed.get()) {
          getNonFloodingLogger().error(
              "Attempted to use closed appender named [" + name + "].");
          return;
        }

        if (!active.get()) {
          getNonFloodingLogger().error(
              "Attempted to log with inactive named [" + name + "].");
          return;
        }

        append(event);

      } finally {
        lock.releaseReadLock();
      }

    } finally {
      guard.set(null);
    }
  }

  /**
   * Set the layout for this appender. Note that some appenders have their own
   * (fixed) layouts or do not use one. For example, the [EMAIL PROTECTED]
   * org.apache.log4j.net.SocketAppender} ignores the layout set here.
   */
  public void setLayout(Layout layout) {
    this.layout = layout;
  }

  /**
   * Set the name of this Appender.
   */
  public void setName(String name) {
    this.name = name;
  }

  /**
   * Set the threshold level. All log events with lower level than the
   * threshold level are ignored by the appender.
   */
  public void setThreshold(Level threshold) {
    this.threshold = threshold;
  }

  /**
   * Returns true if this appender is closed.
   * An appender can be closed only once.
   */
  public boolean getClosed() {
    return closed.get();
  }

  /**
   * Called to clean up the appender.
   * Marked as <code>final</code> to prevent subclasses from accidentally
   * overriding and forgetting to call <code>super.close()</code>.
   * Calls [EMAIL PROTECTED] #internalClose} when completed.
   * Implementation note:  Obtains a write lock before starting close.
   */
  public final void close() {
    boolean wasClosed;
    getWriteLock();
    try {
      wasClosed = closed.set(true);
    } finally {
      lock.releaseWriteLock();
    }

    if (!wasClosed)
      internalClose();
  }

  /**
   * Called to check if the appender is closed.
   */
  public boolean isClosed() {
    return closed.get();
  }

  /**
   * Returns a string representation of this object.
   */
  public String toString() {
    return super.toString() + " name=" + name + 
      " threshold=" + threshold + " layout=" + layout;
  }

  // PROTECTED METHODS

  /**
   * Subclasses of <code>ConcurrentAppender</code> should implement this method
   * to perform actual logging. 
   * This object holds a read lock during this method.  This method may be
   * called simultaneously by multiple threads.
   */
  protected abstract void append(LoggingEvent event);

  /**
   * Subclasses must implement their own close routines.
   * This is guaranteed to be called only once during [EMAIL PROTECTED] #close}.
   */
  protected abstract void internalClose();

  /**
   * Obtains a write lock that locks logging to [EMAIL PROTECTED] #append}.
   * This is normally done when changing output behavior, closing and reopening
   * streams, etc.  Call [EMAIL PROTECTED] #releaseWriteLock} to resume logging.
   * <p>
   * Usage pattern:
   <pre>
   getWriteLock();
   try {
      // ...
   } finally {
      releaseWriteLock();
   }
   </pre>
   */
  protected void getWriteLock() {
    lock.getWriteLock();
  }

  /**
   * Caling this method allows concurrently executing logs by this object.
   * @see #getWriteLock
   */
  protected void releaseWriteLock() {
    lock.releaseWriteLock();
  }

  /**
   * Finalize this appender by calling this [EMAIL PROTECTED] #close} method.
   */
  protected void finalize() {
    if (!getClosed())
      getLogger().debug("Finalizing appender named [{}].", name);
    close();
  }

  /**
   * Convenience class.
   */
  static class FilterChain {

    private Filter headFilter = null;
    private Filter tailFilter = null;
   
    public synchronized boolean accept(LoggingEvent event) {
      Filter f = headFilter;
      while (f != null) {
        switch (f.decide(event)) {
          case Filter.DENY:
            return false;
          case Filter.ACCEPT:
            return true;
          case Filter.NEUTRAL:
            f = f.getNext();
        }
      }
      return true;
    }

    public synchronized void addFilter(Filter newFilter) {
      if (headFilter == null) {
        headFilter = newFilter;
        tailFilter = newFilter;
      } else {
        tailFilter.setNext(newFilter);
        tailFilter = newFilter;
      }
    }

    public synchronized Filter getHead() {
      return headFilter;
    }

    public synchronized void clear() {
      headFilter = null;
      tailFilter = null;
    }

  }

}
/*
  File: SynchronizedBoolean.java

  Originally written by Doug Lea and released into the public domain.
  This may be used for any purposes whatsoever without acknowledgment.
  Thanks for the assistance and support of Sun Microsystems Labs,
  and everyone contributing, testing, and using this code.

  History:
  Date       Who                What
  19Jun1998  dl               Create public version
*/

package org.apache.log4j.concurrent;

/**
 * A class useful for offloading synch for boolean instance variables.
 * A cut down version of the original Doug Lea class.
 */
public final class SynchronizedBoolean {

  private boolean value;

  /** 
   * Make a new SynchronizedBoolean with the given initial value,
   * and using its own internal lock.
   **/
  public SynchronizedBoolean(boolean initialValue) { 
    value = initialValue; 
  }

  /** 
   * Return the current value 
   **/
  public synchronized boolean get() { return value; }

  /** 
   * Set to newValue.
   * @return the old value 
   **/
  public synchronized boolean set(boolean newValue) { 
    boolean old = value;
    value = newValue; 
    return old;
  }

  public String toString() { return String.valueOf(get()); }

}

/*
 * Copyright 1999,2004 The Apache Software Foundation.
 * 
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 * 
 *      http://www.apache.org/licenses/LICENSE-2.0
 * 
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */

package org.apache.log4j.concurrent;

import org.apache.log4j.spi.LoggingEvent;

import java.io.IOException;
import java.io.OutputStream;
import java.io.OutputStreamWriter;
import java.io.Writer;
import org.apache.log4j.Layout;

// Contibutors: Jens Uwe Pipka <[EMAIL PROTECTED]>
//              Ben Sandee

/**
   WriterAppender appends log events to a [EMAIL PROTECTED] java.io.Writer} or an
   [EMAIL PROTECTED] java.io.OutputStream} depending on the user's choice.

   @author Ceki G&uuml;lc&uuml;
   @since 1.1 */
public class WriterAppender extends ConcurrentAppender {
  
  /**
     Immediate flush means that the underlying writer or output stream
     will be flushed at the end of each append operation. Immediate
     flush is slower but ensures that each append request is actually
     written. If <code>immediateFlush</code> is set to
     <code>false</code>, then there is a good chance that the last few
     logs events are not actually written to persistent media if and
     when the application crashes.

     <p>The <code>immediateFlush</code> variable is set to
     <code>true</code> by default.

  */
  protected boolean immediateFlush = true;

  /**
     The encoding to use when opening an InputStream.  <p>The
     <code>encoding</code> variable is set to <code>null</null> by
     default which results in the utilization of the system's default
     encoding.  */
  protected String encoding;

  /**
   * This is the [EMAIL PROTECTED] Writer Writer} where we will write to.
   * Do not modify this class without obtaining a write lock.
   */
  protected Writer writer;

  /**
   * This default constructor does nothing.  
   */
  public WriterAppender() {
  }

  /**
     If the <b>ImmediateFlush</b> option is set to
     <code>true</code>, the appender will flush at the end of each
     write. This is the default behavior. If the option is set to
     <code>false</code>, then the underlying stream can defer writing
     to physical medium to a later time.

     <p>Avoiding the flush operation at the end of each append results in
     a performance gain of 10 to 20 percent. However, there is safety
     tradeoff involved in skipping flushing. Indeed, when flushing is
     skipped, then it is likely that the last few log events will not
     be recorded on disk when the application exits. This is a high
     price to pay even for a 20% performance gain.
   */
  public void setImmediateFlush(boolean value) {
    immediateFlush = value;
  }

  /**
     Returns value of the <b>ImmediateFlush</b> option.
   */
  public boolean getImmediateFlush() {
    return immediateFlush;
  }

  /**
   * Activates options.  Should be called only once.
   */
  public void activateOptions() {

    if (getLayout() == null) {
      getLogger().error(
        "No layout set for the appender named [{}].", name);
      return;
    }
    
    if (this.writer != null) {
      active.set(true);
    }

  }

  /**
     This method is called by the [EMAIL PROTECTED] AppenderSkeleton#doAppend}
     method.

     <p>If the output stream exists and is writable then write a log
     statement to the output stream. Otherwise, write a single warning
     message to <code>System.err</code>.

     <p>The format of the output will depend on this appender's
     layout.

  */
  public void append(LoggingEvent event) {
    subAppend(event);
  }

  /**
     Close this appender instance. The underlying stream or writer is
     also closed.
     <p>Closed appenders cannot be reused.
   */
  protected void internalClose() {
    closeWriter();
  }

  /**
   * Close the underlying [EMAIL PROTECTED] java.io.Writer}.
   */
  protected void closeWriter() {
    try {
      getWriteLock();
      if (this.writer == null)
        return;
      try {
        // before closing we have to output the footer
        writeFooter();
        this.writer.close();
        this.writer = null;
      } catch (IOException e) {
        getLogger().error("Could not close writer for WriterAppener named "+name, e);
      }
    } finally {
      releaseWriteLock();
    }
  }

  /**
     Returns an OutputStreamWriter when passed an OutputStream.  The
     encoding used will depend on the value of the
     <code>encoding</code> property.  If the encoding value is
     specified incorrectly the writer will be opened using the default
     system encoding (an error message will be printed to the loglog.  */
  protected OutputStreamWriter createWriter(OutputStream os) {
    OutputStreamWriter retval = null;

    String enc = getEncoding();

    if (enc != null) {
      try {
        retval = new OutputStreamWriter(os, enc);
      } catch (IOException e) {
        getLogger().warn("Error initializing output writer.");
        getLogger().warn("Unsupported encoding?");
      }
    }

    if (retval == null) {
      retval = new OutputStreamWriter(os);
    }

    return retval;
  }

  public String getEncoding() {
    return encoding;
  }

  public void setEncoding(String value) {
    encoding = value;
  }

  /**
    <p>Sets the Writer where the log output will go. The
    specified Writer must be opened by the user and be
    writable.

    <p>The <code>java.io.Writer</code> will be closed when the
    appender instance is closed.


    <p><b>WARNING:</b> Logging to an unopened Writer will fail.
    <p>
    @param writer An already opened Writer.  */
  public void setWriter(Writer writer) {
    // close any previously opened writer
    closeWriter();
    
    try {
      getWriteLock();
      this.writer = writer;
      writeHeader();
    } finally {
      releaseWriteLock();
    }
  }

  /**
   * Actual writing occurs here. 
   * <p>Most subclasses of <code>WriterAppender</code> will need to override 
   * this method.
   */
  protected void subAppend(LoggingEvent event) {
    try {

      // Format first
      Layout layout = getLayout();
      String se = layout.format(event);
      String st[] = null;
      if (layout.ignoresThrowable()) {
        st = event.getThrowableStrRep();
      }

      // Write as one message
      synchronized (this.writer) {
        this.writer.write(se);
        if (st != null) {
          int len = st.length;
          for (int i = 0; i < len; i++) {
            this.writer.write(st[i]);
            this.writer.write(Layout.LINE_SEP);
          }
        }
      }

      if (immediateFlush)
        this.writer.flush();

    } catch (IOException ioe) {
      boolean wasOrder = active.set(false);
      if (wasOrder) {
        getLogger().error("IO failure for appender named "+name, ioe);
      }
    }
  }

  /**
     The WriterAppender requires a layout. Hence, this method returns
     <code>true</code>.
  */
  public boolean requiresLayout() {
    return true;
  }

  /**
   * Write a footer as produced by the embedded layout's [EMAIL PROTECTED] 
   * Layout#getFooter} method.  
   */
  protected void writeFooter() {
    Layout layout = getLayout();
    if (layout != null) {
      String f = layout.getFooter();

      if ((f != null) && (this.writer != null)) {
        try {
          this.writer.write(f);
        } catch(IOException ioe) {
          active.set(false);
          getLogger().error("Failed to write footer for Appender named "+name, ioe);
        }
      }
    }
  }

  /**
   * Write a header as produced by the embedded layout's [EMAIL PROTECTED] 
   * Layout#getHeader} method.  
   */
  protected void writeHeader() {
    Layout layout = getLayout();
    if (layout != null) {
      String h = layout.getHeader();

      if ((h != null) && (this.writer != null)) {
        try {
          this.writer.write(h);
          this.writer.flush();
        } catch(IOException ioe) {
          active.set(false);
          getLogger().error("Failed to write header for WriterAppender named "+name, ioe);
        }
      }
    }
  }

}

---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]

Reply via email to