logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From John Vasileff <john.li...@gmail.com>
Subject Re: log4j2 parameterized msg with throwable
Date Fri, 23 Sep 2011 22:05:22 GMT
On Sep 23, 2011, at 3:37 AM, Ralph Goers wrote:

> On Sep 22, 2011, at 10:16 PM, Curt Arnold wrote:
>> Been lurking and watching the thread, wanted to throw some comments out without fully
following the thread. Take everything with a grain of salt.
> Why? Your input is just as valuable as everyone else's.
>> log4j 1.2's AsyncAppender does a bit of this by calling all sorts of methods to force
the lazy initialization of the event prior to the event being queued for processing by the
worker thread. This can result in a lot of unnecessary work on the calling thread copying
things like the MDC that might but might not be used in the eventual message formatting.
> For some reason I haven't gotten around to the AsyncAppender.  I'm afraid some copying
of data when generating the LogEvent is inevitable. 
>> Performing the rendering of the message on the calling thread is also not desirable
since things like formatting floating point numbers can be surprisingly expensive.
> One advantage of the Message interface is that it can provide information that can help
determine when it should be rendered. For example, in addition to the initialize method John
proposed for the DeferredMessage it could also indicate when it should be deferred to.  Of
course, Messages never need to format themselves until getFormattedMessage is called.
>> In some of my earlier design experiments, I was very fond of having the formatter/layout
object supporting a two phase approach where the layout had an opportunity to "extract" from
the logging event on the calling thread and then process the extracted information later on
the worker thread. The extraction method would be responsible to assemble the information
that it needed into an arbitrary immutable object that would be passed blindly by the framework
to the formatting phase at the proper time. The implementation had the choice of whether it
wanted to render all the way to String on the calling thread (say if it were cheap) on do
the minimum to get immutable objects in the calling thread and do all the heavy lifting on
the worker thread.
> I'm not sure I see the benefit of creating another object. You still need the LogEvent.
Most of the work to insure the LogEvent can be passed to another thread really needs to be
done anyway. Currently the constructor copies the MDC and NDC and a ThrowableProxy is constructed
if a Throwable is present. About the only things that aren't being done then is the setting
of the caller's StackTraceElement and setting the name of the current thread.  It is a simple
matter to have the AsyncAppender cause those to be set.  
> FWIW, the LogEvent should be immutable from the perspective of anything using it. Since
LogEvent is an interface and only exposes get methods this would be true, except that getContextMap
and getContextStack don't say they return unmodifiable objects and they implementation isn't
returning immutable objects. They should.
>> Without getting the layout participating, you almost will be doing unnecessary work
on the calling thread.
> I don't necessarily disagree with this part. For example, the Converters that deal with
the caller's location could call LogEvent.getSource during the first call to make sure the
required information in the LogEvent is captured. Of course, they would call that same method
during the rendering but that second call would be very inexpensive.
>> I fleshed this approach out several years ago at https://svn.apache.org/repos/asf/logging/sandbox/experimental/pattern-layout
if anyone wants to take a look for ideas.
> I'll take a look at this.  
> Ralph

While this doesn't address all of the points, a few thoughts:

As Joern has pointed out, mutability is at odds with asynchronous logging.  The link he provided
elsewhere: http://techblog.appnexus.com/2011/webkit-chrome-safari-console-log-bug/

So some of the work really cannot be deferred.  But, since many params will be immutable anyway,
ParameterizedMessage and others could create an immutable Object[] instead of a String[] as
is currently done.  This would safely delay toString for all standard immutable types (i.e.
no float conversions in the original thread).  For some Message types this is really essential
as they may need access to the original Floats, Integers, Longs, etc. to perform proper formatting,
for example, a java.util.Formatter message type.


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

View raw message