[logback-dev] RFC: LoggingEvent redesign

[Joern Huxhorn]

Ceki Gulcu wrote:
> Joern Huxhorn wrote:
>
> > I also still think that the LoggingEvent should not know about the
> logic
> > behind the transformation from the Object[] arguments to the String[]
> > arguments.
>
> I am quite puzzled by your line of thought expressed above. Looking at
> d.h.lilith.data.logging package, while the LoggingEvent class does not
> know about message formatting, the logic is present in the Message
> class (in the same package) does know about message formatting
> logic. It seems like d.h.lilith.data.logging.LoggingEvent class
> delegates message formatting logic to a subcomponent but the logic is
> still there. (I actually like the way its done. However, I am confused
> about your suggestion to remove the logic taking your code as example,
> while that code contains the said logic.)
I wasn't referring to the message formatting logic.I was referring to
the logic required to convert the Object[] to the String[].

I can understand your confusion because logic implemented by SLF4J's
MessageFormatter.arrayFormat(String messagePattern, Object[] argArray)
is a three-step-process in my case.

The call to (my) MessageFormatter.format(String messagePattern, String[]
arguments) is actually just the last step and is there to support
one-time lazy initialization. This could have been implemented using a
wrapper to keep LoggingEvent even "purer" but I decided to implement it
that way for performance reasons.

It's a static method without LoggingEvent/Message dependency for better
testability (and also because it kind of evolved from simply calling the
SLF4J formatter to what it is now).

The logic I was meaning is contained in int
countArgumentPlaceholders(String messagePattern) and ArgumentResult
evaluateArguments(String messagePattern, Object[] arguments).
This code is only executed during creation of the LoggingEvent. It
would/should be contained in SLF4J and not in Logback because it could
be the same for all SLF4J implementations. The String[] is contained in
the ArgumentResult.
>> Therefore I'd suggest to define void setArgumentArray(String[])
>> instead of void setArgumentArray(Object[]) (see
>> http://jira.qos.ch/browse/LBCLASSIC-45 )
>
> As Ralf mentioned, under certain circumstances it may be useful to
> place objects types other than strings as parameters to logging
> event. In my previous proposal for ILoggingEvent the
> getArgumentArray() method returned String[]. I think this should be
> modified to Object[] because even if only strings are serialized, we
> should probably not impact local usage of parameters. ILoggingEvent
> then becomes:
I knew that somebody posted to one of the lists that he's using the
Object[] feature in his code but I couldn't remember who it was. Sorry,
Ralph.

I can absolutely see Ralphs point but I'd consider it downright
dangerous to defer the evaluation to Strings, especially in case of
asynchronous appenders.

Take, for example, an object that is persisted using Hibernate. Calling
toString() at the wrong time could very well lead to a LazyInitException.

Or worse, what if an Object changes state (and string representation)
between the logging call and the evaluation of the message? The message
would essentially contain a lie. It would seem that the call to the
logging method was different than it was in reality.

Imagining to debug a problem like this is pure horror and would mean
"forget logging, use a debugger" all over again :(

And, last but not least, transforming to String[] immediately would also
mean that any synchronization/locks would still be the way they (most
likely;)) should be.

Concerning your use case, Ralph, aren't you using an XLogger instance
for that kind of magic? Couldn't you implement the "magic" part in the
XLogger.

> As for your suggestion to make LoggingEvent a dumb object with only
> getters and setters, since several LoggingEvent fields are computed
> lazily, the computation logic would need to be moved somewhere else,
> possibly into appenders, which seems like a bad idea to me.
This logic would reside in the Logger, actually.
It would, in my scenario, transform the Object[] to String[], resolve
the ThreadName and extract CallerData while synchronously creating the
actual LoggingEvent.
ThreadName and CallerData evaluation would be activated/deactivated
globally instead of in an actual appender. That way, there would be no
performance impact if they are not requested.
Evaluating the above mentioned stuff lazily would produce wrong or
inaccurate results if executed from a different thread, am I right?
> On the host where LoggingEvent data is generated, we just can't ignore
> lazy
> computation of certain LoggingEvent fields. Did I misinterpret your idea?
Only the lazy bit. I'd eagerly (synchronously) evaluate everything that
is required in Logger but stuff like the creation of the formatted
message is done lazily.
>
> > I'd have absolutely no problem donating all that code back to both
> Logback and > SLF4J, although some work would be required to backport
> it to jdk < 1.5...
>
> I appreciate the offer. You should perhaps consider filing a
> contributor license agreement.
That wouldn't be a problem, I guess, if I'm not required to sell my soul
or something ;)
Where can  I find it? Just let me know when you think it's necessary.

Joern.