[slf4j-user] Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

[Adam Gent]

I generally agree with your points but I also know there are plenty of
people that completely disagree.
Just check out https://bill.burkecentral.com/2012/05/22/write-your-own-logging-abstraction/

This would be an effort to some what mitigate those who have concerns
have SLF4J and its depenency.

I also wonder if your general opinion isn't stockholm syndrom. Do you
have any idea how many people hate:

SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for
further details.

As a library writer it is fairly annoying to have to deal with users
complaining about. The ones that really care about logging are
generally OK with dealing with extra step


> In that case, my recommendation is: Just use SLF4J as it comes out of the
> box. (I have yet to see a different recommendation.)
>
>> Particularly if this library is high performance or maybe used by
>> android applications. In such case the library would default to the
>> NOPLogger and thus not initialize.
>
>
> How would the library know whether it's called in Android?
> Should it even care?
>

Yes. The reality is often it has to. Maybe not the code itself but the
library maintainers might have to be concerned with Android (this
includes backporting at times).
Of course if you don't care about Android...


> Your proposal does not change anything about the performance of trace
> messages.

Yes it does! I have benchmarked it myself... but alas I don't feel
like pulling JMH out now nor the hassle of dealing with Android to
prove such. Unless you are extremely careful about configuration or
just always globally using the NOPLogger there is generally some
overhead the logging framework will do per call. Now I admit this is a
while ago and I can't remember what logging framework was underneath.
Maybe logback does a better job. I can't imagine it some how has
specially loggers for each level (or maybe it does).


> That's a solved problem: SLF4J is collecting log messages during startup,
> and emitting them once the backend is ready.

That doesn't fix anything. I have to now figure out how to intercept
the backend before it does whatever you know like connecting to a
message queue.

> Also, a production system shouldn't use anything that requires a lot of
> setup to work. Text files and message queues should be fine, database
> connections are a bit too fragile.
> (General principle: Use a more robust mechanism for logging than for what
> your application does.)


Really... I don't think you realize how successful you guys have been
in getting everyone to use SL4J.
You can't even make an HTTP call (let alone use a message queue) these
days with out kicking off a logger (commons HTTP components kicks off
a logger).  Making an HTTP call to setup logging stuff is pretty
useful and the JDK HTTP client is pretty crappy. But yes you are
generally correct and I agree with you.

> That's two logging configurations; in the code, you still have a single
> logger.
> Oh. Right. In
>   Logger logger = LoggerFactory.getLogger(...);
> what's called "Logger" is really just a namespace.
> There is no real configuration going on for it, it's just a name plus two
> internal data fields (which aren't initializated until they are used).
> I.e. setting up a "Logger" object is a very cheap operation; initializing
> SLF4J can take a while because it needs to pull all the configuration files
> together, but your application isn't going to do that in a background thread
> so nothing else happens during that time anyway. (That's why "backend isn't
> ready yet" is *that* much of a problem in practice.)

Application startup time is a big deal... it is the number one hate of
Java I hear most.
But you missed my point that most library consumers (applications)
really just don't give crap about what their libraries are logging.
And when they really really do they can go to the libraries web site
and figure out how to turn on logging. I mean you have to figure out
the logger names anyway.

My point was I only care about the parent framework and my
applications codes logging. It seems a shame to have innocuous
libraries  instantiating 1-3 different libraries indirectly (depending
on how many wrappers, bridges, and converters you are using). It is
just the kind of thing people complain about Java.

All in all I was *trying* to improve the adoption of SLF4J and have it
handle more than 80/20 but 100 of most use cases.
But I suppose most will go off and implement their own stuff anyway.
I wasn't even proposing changing SLF4J.

On Sat, Mar 18, 2017 at 2:20 PM, Joachim Durchholz <jo at durchholz.org> wrote:
> Am 18.03.2017 um 18:02 schrieb Adam Gent:
>>
>> In a framework setting it is very difficult to predict when the
>> logging will be initialized since you often don't control main.
>
>
> That's not a problem: Either you are responsible for main, then you set up
> logging, or you are not responsible for it, then leave that unhandled.
> Forcing a logging policy just because the library thinks it should control
> logging is violating separation of concerns: Libraries shouldn't care.
>
> (There is one exception, if latencies are involved. Just emit a dummy log
> message in the library initialization code to force logger initialization.)
>
>> Besides the framework may want to actually switch from a NOP (or
>> Simple Logger) while it is initializing to a full blown
>> LogFactory.getLogger() after the bootstrap process has finished
>
>
> SLF4J used to do noop logging before it was fully initialized, today it is
> simply collecting the log messages and emitting them until the backend is
> ready.
>
>> It is also actually fairly difficult to unit test logging code since
>> you really don't control the bootstrap process especially since many
>> tests like Spring framework require a special JUnit runner (@RunWith).
>
>
> There are two answers to that.
>
> 1) Consider logging to be the debugger substitute for code that is running
> unattended. In that case, you have no functional requirements, you add log
> messages as you find you need to investigate, and you do not have a need to
> unit test logging.
> If a message is too important to be lost, it is not logging but an audit
> trail; you do not want to use a logging framework.
> (I am aware that not everybody will subscribe to that view. However, I have
> yet to see substantial counterarguments.)
>
> 2) Mock the logger calls. You don't want to verify the exact output anyway,
> which is subject to all kinds of configuration formatting; you may not even
> want to validate that a message has a specific wording, just that a
> logger.warn call happens with a specific set of substitution parameters.
> (I think mocking covers all the use cases that aren't covered by (1).)
>
>> I'm trying to recommend a pattern for libraries that want to do some
>> logging perhaps only for diagnostic and development purposes but
>> logging is not a critical component of the library (perhaps even the
>> logging is too opaque anyway for normal users).
>
>
> In that case, my recommendation is: Just use SLF4J as it comes out of the
> box. (I have yet to see a different recommendation.)
>
>> Particularly if this library is high performance or maybe used by
>> android applications. In such case the library would default to the
>> NOPLogger and thus not initialize.
>
>
> How would the library know whether it's called in Android?
> Should it even care?
>
>> The reality is 99% of libraries that do logging is completely
>> irrelevant to the consumer of the library. The logging is mostly
>> trace.
>
>> In a environment like Android this adds up to be nontrivial
>>
>> amount of performance loss (as well as callstack and method count
>> issues).
>
>
> Your proposal does not change anything about the performance of trace
> messages.
>
>> Finally as another person alluded there is also a chicken and egg
>> problem If I'm trying to bootstrap my application to get ready to
>> configure logging and perhaps use a parsing library (json, yaml
>> whatever) or configuration library and that library uses logging... we
>> now have a problem.
>
>
> That's a solved problem: SLF4J is collecting log messages during startup,
> and emitting them once the backend is ready.
>
> Also, a production system shouldn't use anything that requires a lot of
> setup to work. Text files and message queues should be fine, database
> connections are a bit too fragile.
> (General principle: Use a more robust mechanism for logging than for what
> your application does.)
>
>> Also after  looking at 20 of our various
>> log4j.xml/logback.xml/log4j2.xml config code bases the only loggers we
>> care about are our own and maybe the parent framework (Spring). Thats
>> it.
>
>
> That's two logging configurations; in the code, you still have a single
> logger.
> Oh. Right. In
>   Logger logger = LoggerFactory.getLogger(...);
> what's called "Logger" is really just a namespace.
> There is no real configuration going on for it, it's just a name plus two
> internal data fields (which aren't initializated until they are used).
> I.e. setting up a "Logger" object is a very cheap operation; initializing
> SLF4J can take a while because it needs to pull all the configuration files
> together, but your application isn't going to do that in a background thread
> so nothing else happens during that time anyway. (That's why "backend isn't
> ready yet" is *that* much of a problem in practice.)
> _______________________________________________
> slf4j-user mailing list
> slf4j-user at qos.ch
> http://mailman.qos.ch/mailman/listinfo/slf4j-user



-- 
CTO
SnapHop (snaphop.com)
(twitter) @agentgt (linkedin) http://www.linkedin.com/in/agentgt
(cell) 781-883-5182