Logging formatter in log4j sandbox

 

> -----Original Message-----
> From: Curt Arnold [mailto:carnoldapache.org] Sent: 19 March
2006
22:34
> 
> On Mar 19, 2006, at 1:40 AM, Jaroslaw Kowalski wrote:
> 
> > Small hint from NLog developer:
> >
> > Why don't you pass the raw message with parameter

> placeholders, format 
> > arguments and IFormatProvider down to the logging
engine and defer 
> > calling the actual String.Format to as late as
possible?
> 
> > This way you can avoid the cost of String.Format()
at all 
> if there are 
> > filters (or whatever) which cause the message to
be ignored, while 
> > IsXXXEnabled would return true.
> >
> 
> Since ILog.Debug and similar take an object as the
message 
> parameter, it should be fairly easy to construct an
object 
> from the IFormatProvider and parameters and overload  
> ToString() to call IFormatProvider.Format.  I didn't
pursue 
> that optimization with the log4j sandbox effort, though
I 
> didn't preclude it either.

I think this would be a worthwhile performance improvement
to make.


 
> On Mar 19, 2006, at 11:12 AM, Nicko Cadell wrote:
> > It is also worth mentioning that, unlike log4j, in
log4net the user 
> > does not interact with the Logger directly but
with a wrapper. The 
> > Logger
> > (ILogger) has a Log method that is used to log all
the 
> messages. The 
> > wrapper LogImpl (implements ILog) has all the
Debug/Info/Warn/Error 
> > methods which forward the log call to the Logger
method. 
> The LogImpl 
> > contains the Format methods. If a use wants a
different format 
> > implementation they can write their own wrapper
with user callable 
> > methods.
> > Nicko
> 
> I've quickly reviewed the log4net source code.  One of
the 
> design concerns in the log4j sandbox effort was
avoiding 
> array creation or boxing costs for requests that were
below 
> the threshold.  The ILog.DebugFormat and similar
methods 
> would appear to incur boxing and array creation cost
even if 
> the message was below the threshold.  In performance
testing 
> on Java, those costs were non-trivial.  Ideally, you
would 
> like the cost of a below threshold log request to be
only the 
> cost of logger.IsEnabledFor and to have that cost as
small as 
> possible.

It looks like the log4j sandbox and the .net framework agree
on the
number of override params, 3. This gives signatures like:

void DebugFormat(string format); 
void DebugFormat(string format, object arg0); 
void DebugFormat(string format, object arg0, object arg1); 
void DebugFormat(string format, object arg0, object arg1,
object arg2); 
void DebugFormat(string format, params object[] args); 

 
> The sandbox effort also tries to perform some
optimizations 
> that may not be beneficial on .NET.  For example,
evaluating 
> a simple pattern with only plain substitutions is can
be done 
> faster than calling MessageFormat.format.  The
optimizations 
> should be transparent to the user and do not need to be

> replicated in a .NET implementation if they do not
offer a benefit.

These optimisations may be added later transparently to the
user.
 

> I do like the distinct static class approach, it
separates 
> the logging function from the formatting function but
still 
> allows the short-circuiting and other performance 
> optimizations that motivated combining them.

In that case why not move the Debug, Info, Warn etc..
methods into a
static class?

Log.Debug(logger, message);

Then your logger only needs to have a single method that
takes a Level,
and a message. This has the advantage that a user easily
understands how
to add support for their own levels or different logging
method
signatures, for example:

MyLog.Alarm(logger, message, state);

In addition using the extension methods proposed feature of
C# 3 it
would be possible to decorate the logger with these methods
allowing you
to call logger.Alarm(message, state); 

log4net has chosen a slightly different design which is to
support
wrapper objects that provide the interface to the logger.
The Debug,
Info, Warn etc.. methods are on a simple wrapper object that
forwards to
the nested logger. This design does give us the nice syntax
of
logger.Debug(message) but it does make it harder for the
user to
understand how to add their own log methods, and there is a
higher
memory cost for having the additional wrapper around the
nested logger.

I think that given this historic design decision we should
not introduce
a static class of logging helper methods at this time, as
that would
confuse users further. Removing the current xxxFormat
methods from the
ILog interface will break a number of early adopters, which
I would
rather avoid if possible.


I propose adding format method overrides (see above) for
common numbers
of format param arguments. And also wrapping the format
message in an
object to delay the formatting of the message until after
the appender
filters have run.

Nicko

On Mar 24, 2006, at 5:49 AM, Nicko Cadell wrote:
>
> It looks like the log4j sandbox and the .net framework
agree on the
> number of override params, 3. This gives signatures
like:
>
> void DebugFormat(string format);
> void DebugFormat(string format, object arg0);
> void DebugFormat(string format, object arg0, object
arg1);
> void DebugFormat(string format, object arg0, object
arg1, object  
> arg2);
> void DebugFormat(string format, params object[] args);
>

I originally had the (string format) signature, but removed
it as  
there were no format specifiers that did not require a
corresponding  
parameter.

>
>> The sandbox effort also tries to perform some
optimizations
>> that may not be beneficial on .NET.  For example,
evaluating
>> a simple pattern with only plain substitutions is
can be done
>> faster than calling MessageFormat.format.  The
optimizations
>> should be transparent to the user and do not need
to be
>> replicated in a .NET implementation if they do not
offer a benefit.
>
> These optimisations may be added later transparently to
the user.
>

True.  They were important for the sandbox effort since they
weakened  
the performance argument for the SLF4J style formatter.

>
>> I do like the distinct static class approach, it
separates
>> the logging function from the formatting function
but still
>> allows the short-circuiting and other performance
>> optimizations that motivated combining them.
>
> In that case why not move the Debug, Info, Warn etc..
methods into a
> static class?
>
> Log.Debug(logger, message);
>
> Then your logger only needs to have a single method
that takes a  
> Level,
> and a message. This has the advantage that a user
easily  
> understands how
> to add support for their own levels or different
logging method
> signatures, for example:
>
> MyLog.Alarm(logger, message, state);
>
> In addition using the extension methods proposed
feature of C# 3 it
> would be possible to decorate the logger with these
methods  
> allowing you
> to call logger.Alarm(message, state);
>
>
> log4net has chosen a slightly different design which is
to support
> wrapper objects that provide the interface to the
logger. The Debug,
> Info, Warn etc.. methods are on a simple wrapper object
that  
> forwards to
> the nested logger. This design does give us the nice
syntax of
> logger.Debug(message) but it does make it harder for
the user to
> understand how to add their own log methods, and there
is a higher
> memory cost for having the additional wrapper around
the nested  
> logger.
>
> I think that given this historic design decision we
should not  
> introduce
> a static class of logging helper methods at this time,
as that would
> confuse users further. Removing the current xxxFormat
methods from the
> ILog interface will break a number of early adopters,
which I would
> rather avoid if possible.
>

log4j doesn't have the distinct ILog and ILogger interfaces
and so in  
some ways, the static LogMF and ILog are similar in that
they are  
trying to keep complexity out of the basic logger construct.
 Having  
the distinct static classes is useful for log4j since there
are  
incompatible formatters on the platform and it could be used
with the  
widely deployed log4j 1.2.x . Neither is a concern with
log4net.

>
> I propose adding format method overrides (see above)
for common  
> numbers
> of format param arguments. And also wrapping the format
message in an
> object to delay the formatting of the message until
after the appender
> filters have run.
>

Sounds reasonable.