[slf4j-dev] Release of SLF4J version 1.6.0-RC0

[Joern Huxhorn]

On 30.04.2010, at 19:16, Ceki Gülcü wrote:

> > Using the suggested methods would create illegible logging calls, at
> > least in my opinion, since they differ quite much from the current
> > signature. The current methods enforce a certain order which won't be
> > the case anymore in case of LoggingEvent.
> 
> I agree that building the LoggingEvent prior to calling logger.log
> implies a paradigm change. However, I fail to understand your point
> about "current methods enforce a certain order...". Could you explain?
> 

In case of

logger.log(new LoggerEvent(Level.INFO, new ParameterizedMessage("Foo Bar {}").addParam("FooBar")).set(throwable).add(marker1).add(marker2))

the order is completely different compared to 

logger.info(marker1, "Foo Bar {}", "FooBar", throwable)

It's downright unreadable, at least if taking just a glance. Level is too far on the right. The Throwable is somewhere in the middle.

It's the same reasoning as in Scalas decision to define variables like this:
var x: Integer
The important part, the variable name, is at the first position. The less important part (while just scanning the code), the probably very noisy type, is further to the right.

In case of logging, the most important part while scanning source code is the level.
Yes, my reasoning is mostly based on aesthetics and the ability to read other peoples code quickly. Our brain is a pattern-matching-engine. ;)

> > Concerning the insanity, I'd rather be lazy while using the Logger
> > than while implementing it.
> 
> Of course! I agree with that sentiment but it's also about striking a
> balance. Assuming that the vast majority of logger invocations are
> akin to logger.level(message), only in a small number of cases will
> the user write:
> 
> LoggingEvent event =
>   new LoggingEvent(Level.ERROR, new Message("msg0", "type0"))).add(t);
> logger.log(event);
> 
> With this API change, simple things remain simple and more complex
> thing are made possible.
> 

Comments below.

> > (Concerning the performance info at
> > http://bugzilla.slf4j.org/show_bug.cgi?id=31#c82 I'd even consider
> > adding methods with 4 and 5 arguments :p)
> 
> Considering that only a very small proportion of logger calls have 4
> or 5 arguments, the expected performance gain obtained by the addition
> of these methods should be negligible, especially considering that
> although calling new Object[] is noticeably slower but not in way which
> offsets the diminishing probability of having 4 or 5 params.

I wasn't trying to suggest we should add these. I think we shouldn't. If performance was THE most important factor then, yes, we should, but you are right that these are corner-cases that won't happen too often. You shouldn't forget, however, that the addition of Throwable support essentially reduces the really available amount of fixed arguments to 2, not 3, in that case.
Again, I think that this is acceptable anyway, even though most of my log-messages have >2 parameters.

> 
> > This means I'd happily perform the monkey-work of implementing
> > 4*5(LogLevels)*6(SLF4J-implementations) methods but I'm not really
> > interested very much in Logger.log(LoggerEvent)
> 
> I actually agree with the way you brake down the problem. It's really a
> trade between monkey-work on side of SLF4J developers versus
> inconvenience to the users. The LoggingEvent paradigm is not that
> awful and much more extensible. (Add a new method to LoggingEvent
> instead of adding Nx5 new methods to logger, times its various
> implementations.)
> 

I really think that LoggingEvent is a very private property of the backend-implementation that shouldn't "leak" into SLF4J.
I also share Ralphs concern about reusing LoggingEvent instances multiple times. Code like that will happen and the probability increases with the complexity of it's creation - no matter what the documentation will say about this. People won't read it anyway until it's too late (i.e. until they already have some inexplicable behavior). ;)

The main idea of the Message interface was to prevent such a tight coupling while offering a maximum of flexibility.

> > I don't agree that this problem is a problem at all.
> 
> Given that the logger interface has to deal with 6 different types,
> namely Level, Marker, String (the message), Message (typed message),
> Throwable, Object[] (the arguments), combinatorial explosion in method
> signatures cannot be avoided. Bug 70, which you know well, is an
> example of possible interferences caused by just two different types
> (Object[] and Throwable).
> 
> 
> Around March of this year, Gunnar Wagenknecht observed that markers
> should viewed as tags and the current marker mechanism is over
> engineered. Unfortunately, I think he is right **. At this stage, it
> would be very inelegant to add Marker[] as a new parameter type to the
> logger interface. With the LoggerEvent paradigm, it the user wishes to
> add several markers to the event, she repeatedly calls
> event.add(marker). For example,
> 
>  new LoggingEvent("hello world").add(marker1).add(marker2);
> 
> That's it.
> 
> ** http://www.qos.ch/pipermail/slf4j-dev/2010-March/002875.html
> 

How about only adding

logger.debug(Message)
logger.debug(Message, Throwable)

leaving out the Marker?

That way the Message implementation might opt-in to add Marker-support as seen fit.

I'd like to point out, though, that I haven't thought this through, yet.

I think it would likely create rather big problems, including TurboFilters that won't properly match on Markers anymore... which would create a large amount of confusion for the user.

The main-point of Markers, for me, is the ability to use them for efficient filtering in Logback (and Lilith).

I never liked the hierarchy-aspect of them, especially since they are supposed to be global.

In my opinion, the marker-hierarchy shouldn't be created in the software but in the configuration instead. Under no circumstance should other modules be able to change my marker-hierarchy.  I once reported a bug about recursive marker-hierarchies that you fixed by preventing recursion at all. This has the effect that the module that creates the Marker first will be able to decide on the hierarchy while a module loaded later-on in the application will be stuck on the previously created hierarchy - even if it's logging is expecting an entirely different one. This is a catastrophe waiting to happen - which is why I'm not using them in that way in my code.

I'm also not sure about possible classloader-woes concerning MarkerFactory. [1][2]
I haven't checked this but I suspect there could be problems with Markers comparable to those of custom java.util.logging.Level.

Beside that, I think the Markers ENTERING, EXITING and THROWING should be used without being put into a TRACING marker. The grouping of those three markers into a TRACING group should be done in the Logback config and filters could then filter on that group.
But this after-the-fact discussion isn't helping anymore.
One way to fix it, though, would be not caching Markers in MarkerFactory at all.

The use-case described by Gunnar could (and IMHO: should) be handled using the MDC, not Markers. He could call MDC.put("CONFIDENTIAL","true") and perform special handling that way.

Both ways assume that the Logging system is evaluating either Marker or MDC which isn't the wisest thing to do.
Confidential info should NEVER be logged, IMHO, regardless of the logging configuration.

 
> > If it's simply a matter of the amount of work that'll be required
> > then I'd be happy to help out.
> 
> Thank you. I appreciate the offer.
> 

You're welcome.

Cheers & have a nice weekend,
Joern.

[1] http://blogs.sun.com/fkieviet/entry/classloader%5Fleaks%5Fthe%5Fdreaded%5Fjava
[2] http://blogs.sun.com/fkieviet/entry/how%5Fto%5Ffix%5Fthe%5Fdreaded