Mailing-List: contact log4j-dev-help@logging.apache.org; run by ezmlm
Precedence: bulk
Reply-To: "Log4J Developers List" <log4j-dev@logging.apache.org>
Received-SPF: neutral (asf.osuosl.org: local policy)
Mime-Version: 1.0 (Apple Message framework v746.2)
Content-Transfer-Encoding: 7bit
Message-Id: <361544A9-C4AD-4614-BB02-548BC6ECBFF9@apache.org>
Content-Type: text/plain; charset=US-ASCII; delsp=yes; format=flowed
To: Log4J Developers List <log4j-dev@logging.apache.org>
From: Curt Arnold <carnold@apache.org>
Subject: Experimental log4j formatter in sandbox
Date: Thu, 12 Jan 2006 00:51:40 -0600

I committed a pass at external message formatting classes in the  
sandbox.  The code can be checked out using:

svn co http://svn.apache.org/repos/asf/logging/sandbox/log4j/ 
formatter formatter

and can be built using either Maven (JDK 1.5 only) or Ant.  The Ant  
build can produce both a JDK 1.5 compatible jar (build with ant jar  
or mvn jar:jar) which supports varargs and the java.util.Formatter  
formatter and a (hopefully) JDK 1.3 compatible jar (build with ant  
jar-java2) which substitutes Object[] for Object... and omits support  
for the java.util.Formatter.  The formatter was built and tested with  
log4j 1.2.13 (latest in Maven) and should work with earlier log4j  
1.2.x (may throw MethodNotFound exceptions if trace() methods are  
used with pre-TRACE enabled log4j's) and log4j 1.3.

log4j 1.3, SLF4J and NLOG4J provide methods that take a substitution  
pattern and one or more parameters used to form the message where the  
substitution is only performed if the logger threshold is satisfied.   
For example:

logger.debug("The {} jumped over the moon {} times", "cow", new  
Integer(5));

One of my concerns was introducing yet another pattern syntax when  
Java class libraries already have two (java.text.MessageFormat and  
java.util.Formatter).  I had originally thought that the substitution  
pattern format was a subset of that supported by  
java.text.MessageFormat, however java.text.MessageFormat would  
require parameter numbers within the braces (for example, "The {0}  
jumped over the moon {1} times").

Instead of enshrining one pattern syntax, the external formatters  
provide three different utility classes with identical methods that  
each use a different formatter.  The class names are short since a  
previous concern with this approach was code bloat.  All the classes  
are (currently) in org.apache.log4j.formatter.  They are:

LogF - uses java.util.Formatter (name should invoke fond memories of  
printf)
LogMF - uses java.text.MessageFormat (adds M for Message)
LogSF - uses existing log4j 1.3 syntax (adds S for Simple)

The previous line could be written as:

LogF.debug(logger, "The %s jumped over the moon %d times", "cow", 5);

LogMF.debug(logger, "The {0} jumped over the moon {1} times", "cow", 5);

LogSF.debug(logger, "The {} jumped over the moon {} times", "cow", 5);

Each class offers identical sets of methods for each level (including  
TRACE).  Each method takes a Logger and a pattern string as the first  
two arguments.  There are methods with three parameters for Object,  
each of the primitive types and either Object... (JDK 1.5) or Object 
[] and a 4 and a 5 parameter method with either 2 or 3 Object  
parameters.  The 3 parameter methods with primitives should eliminate  
most unnecessary object wrapping costs.  If there is a need to have  
two or more primitives, JDK 1.5 will autobox the primitives and use  
either the 4, 5 or vararg methods as appropriate, on JDK 1.3, you  
would need to explicitly box the primitives and use the 4, 5 or Object 
[] methods.

//  JDK 1.5 - calls LogSF.debug(Object, Object)
LogSF.debug(logger, "Iteration {} of {}", i, n);

//  JDK 1.3 - also calls LogSF.debug(Object, Object)
LogSF.debug(logger, "Iteration {} of {}", new Integer(i), new Integer 
(n));

Each of these may incur the cost of creating 2 new Integer objects  
for the duration of the call even if the logger threshold is not  
satisfied.

The primary design goal was to minimize the cost of ineffective log  
requests by deferring the cost of formatting, parameter boxing and  
array creation until after the isEnabledFor() is checked.  The cost  
of formatting, boxing and array creation is assumed to be small  
compared to the append cost and there has been no attempt to optimize  
those costs when the threshold is satisfied.  No performance  
evaluation has been attempted yet and the assumptions need to be  
confirmed.

I assume the JVM will be able to effectively "in-line" the body of  
the method calls so that:

LogMF.debug(logger, "The {0} jumped over the moon {1} times", "cow", 5);

results in code that is nearly indistinguishable in performance from:

if (logger.isDebugEnabled()) {
    logger.debug(MessageFormat.format("The {0} jumped over the moon  
{1} times", new Object[] { "cow", new Integer(5) }));
}

It is possible that the Java 5 JVM is smart enough to defer boxing  
and array creation in the vararg logging methods resulting in no  
performance benefit from the non-vararg methods.  In that case, then  
all of the non-vararg methods could be eliminated from LogF since it  
only exists in the JDK 1.5.  Probably would want to still support  
them for the other formatters to preserve calling compatibility  
between the JDK 1.3+ and the JDK 1.5 implementations of the formatters.

Unlike the log4j 1.3 and SLF4J implementations, the LogSF will  
support more than 2 substitution parameters.  The implementation is  
different and may need to be tweaked to exactly reproduce the log4j  
1.3 and SLF4J behavior.  For example, LogSF doesn't attempt to  
provide any escaping mechanism to allow "{}" to appear in a  
message.   I'm not sure if log4j 1.3 or SLF4J do.

The methods should only throw unchecked exceptions if logger is null  
or if a substitution parameter's toString method throws an  
exception.  They should swallow exceptions due to bad patterns or  
pattern/parameter type mismatches.  In general, they will just output  
the pattern without substitution if there is an exception.

I will attempt to gather some performance measures over the next few  
days.

The Ant build by default attempts to locate log4j-1.2.13 and  
junit-3.8.1 in the user's Maven2 repository.  Use

ant -Dlog4j.jar=PATH_TO_LOG4J -Djunit.jar=PATH_TO_JUNIT

to specify different locations (or specify them in build.properties).


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org