[slf4j-dev] [Bug 112] New: Further MessageFormatter enhancements and fixes

[bugzilla-daemon at pixie.qos.ch]

http://bugzilla.slf4j.org/show_bug.cgi?id=112

           Summary: Further MessageFormatter enhancements and fixes
           Product: SLF4J
           Version: 1.5.x
          Platform: All
        OS/Version: All
            Status: NEW
          Severity: enhancement
          Priority: P1
         Component: Core API
        AssignedTo: dev at slf4j.org
        ReportedBy: joern at huxhorn.de


I'd suggest the following MessageFormatter enhancements:

1.) support for arrays contained in Map & Collection.
2.) support for recursive Maps, Collections & Object[] with better String
representation.
3.) support for Throwable during toString execution.

More info about 1.):
They are currently still displayed using the default toString(). So while
arrays of any kind as an argument are already displayed in a human-readable
manner, the same isn't the case for arrays contained in either Collection or
Map.

More info about 2.):
The current implementation supports recursive Object[] the same way as
Arrays.toString(Object[]) does in Java5. This can be enhanced.

I implemented the following behavior in my Lilith MessageFormatter:
[...fully.qualified.ClassName at identityHashCodeInHex...] (the same as
[...o.toString()...] if toString has not been implemented).

Recursive Maps & Collections will currently throw an StackOverflowError because
AbstractMap.toString() and AbstractCollection.toString() is only halfheartedly
preventing recursion, i.e. only a direct recursion where the Map/Collection is
directly contained in itself.

Examples:
List a=new ArrayList();
List b=new ArrayList();
b.add(a);
a.add(b);
// the following line will throw an java.lang.StackOverflowError!
a.toString();

Map a=new HashMap();
Map b=new HashMap();
b.put("bar", a);
a.put("foo", b);
// the following line will throw an java.lang.StackOverflowError!
a.toString();

We should aim to provide valuable logging information even if ordinary Java
would fail.

More info on 3.):
I implemented the following behavior in my Lilith MessageFormatter:
[!!!fully.qualified.ClassName at identityHashCodeInHex=>fully.qualified.Throwable:ThrowableMessage!!!]
if ThrowableMessage is different to fully.qualified.Throwable, otherwise
[!!!fully.qualified.ClassName at identityHashCodeInHex=>fully.qualified.Throwable!!!] 

This isn't a far-fetched scenario.

A RuntimeException during a toString() currently results in non-execution of
the log method and probably even in an application crash.
One quite realistic scenario is a org.hibernate.LazyInitializationException
thrown by a Hibernate proxy if the data hasn't been prefetched already and the
session has already been closed.
That way it would be possible for code executing perfectly well with debugging
disabled to fail miserably after enabling it. It could cause the application to
crash.
This is especially the case if the logging is happening in the business code
layer and hibernate is only used in production but not in test cases...

Another example would be a recursive Map or Collection in a custom class that's
printing it in it's toString() method or simply a bug in a toString() method.

In all those cases logging would be of big use while analyzing the problem.

Please take a look at
http://lilith.svn.sourceforge.net/viewvc/lilith/trunk/lilith-data/logging/src/main/java/de/huxhorn/lilith/data/logging/MessageFormatter.java?view=markup
as well as
http://lilith.svn.sourceforge.net/viewvc/lilith/trunk/lilith-data/logging/src/test/java/de/huxhorn/lilith/data/logging/MessageFormatterTest.java?view=markup
for my solution to the mentioned problems and feel free to take over anything
you like (changing the code back to 1.4, of course).

My code separates the creation of the String[] from the creation of the
formatted message, though, which is something I'd also strongly suggest for
Logback in the case of asynchronous Appenders.

Related bugs:
http://bugzilla.slf4j.org/show_bug.cgi?id=70
"logging a stack trace along with a parameterized string" solution proposal
Because my MessageFormatter implements the described behavior.

http://jira.qos.ch/browse/LBCLASSIC-45
Suggestion: Make LoggingEvent dumber, Logger more intelligent
Just some more discussion about the place and time where all the logic should
happen. All relevant data, i.e. converting argument Object[] to String[],
obtaining Throwable information and CallStack, should in my opinion done ASAP
after realizing that an event is actually needed. Before any Appender is
executed.

http://jira.qos.ch/browse/LBCLASSIC-32
Serialization of objectArray in LoggingEvent does not always work
This bug is fixed but the report contains some valueable discussion.

http://bugzilla.slf4j.org/show_bug.cgi?id=31
Varargs for Logger methods
Just because I'd really like this fixed *somehow* and it's somewhat related to
#70.

Beside all that, I'm open to discussion about the various outputs like "[...",
"...]", "[!!!", "=>", ":" and "!!!]". What do you think about them? Any better
idea?


-- 
Configure bugmail: http://bugzilla.slf4j.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.