Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

classic Classic list List threaded Threaded
29 messages Options
12
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Adam Gent
Many library writers want to use SLF4j but may want to avoid the
default initialization and binding process. In fact if it is a library
and not a framework I recommend something like what I'm proposing.

I have written a single very small copy and paste class that you can
put in your own library to avoid default SLF4J initialization while
allowing consumers of your library to pick whatever SLF4J
initialization they like through the ServiceLoader mechanism. The
class is meant to be copied and pasted such that you pick your own
package (namespace) for the ServiceLoader part.

The code is available at this github gist:

https://gist.github.com/agentgt/28dc6e9724cb8b96ca08fc147476a7de


There are several reasons why if you are a library writer to consider
this pattern:

 * Often library users don't want to see the annoying default missing
slf4 binding messages
 * Performance reasons. By defaulting to NOP you prevent accidental
performance problems by a user of the library.
 * You allow for even greater logging configuration and separation
than possible with SL4J. For example one library could be configured
to use a Logback SLF4J and another Log4j legacy SLF4J.
 * If the library used to configured a down stream logging framework
(ie logback) you might need interception (ie SubstituteLogger).

Thoughts?

I'm hoping perhaps the SL4J documentation recommend something like
this for library writers.

-Adam

--
CTO
SnapHop (snaphop.com)
(twitter) @agentgt (linkedin) http://www.linkedin.com/in/agentgt
(cell) 781-883-5182
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Joachim Durchholz
Am 17.03.2017 um 16:51 schrieb Adam Gent:
> Many library writers want to use SLF4j but may want to avoid the
> default initialization and binding process.

Are you doing a lazily-initialized wrapper around the logger factory?
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Ceki Gulcu
In reply to this post by Adam Gent

Hi Adam,

Using ServiceLoader.load(LoggerService.class) is quite a good idea. I
think we will have to go that way in future versions of SLF4J to be
compatible with Java 9.

I suppose your library code no longer invokes
org.slf4j.LoggerFactory.getLogger().  How do you use LoggerService in
your libraries?

On 3/17/2017 16:51, Adam Gent wrote:

> Many library writers want to use SLF4j but may want to avoid the
> default initialization and binding process. In fact if it is a library
> and not a framework I recommend something like what I'm proposing.
>
> I have written a single very small copy and paste class that you can
> put in your own library to avoid default SLF4J initialization while
> allowing consumers of your library to pick whatever SLF4J
> initialization they like through the ServiceLoader mechanism. The
> class is meant to be copied and pasted such that you pick your own
> package (namespace) for the ServiceLoader part.
>
> The code is available at this github gist:
>
> https://gist.github.com/agentgt/28dc6e9724cb8b96ca08fc147476a7de
>
>
> There are several reasons why if you are a library writer to consider
> this pattern:
>
>  * Often library users don't want to see the annoying default missing
> slf4 binding messages
>  * Performance reasons. By defaulting to NOP you prevent accidental
> performance problems by a user of the library.
>  * You allow for even greater logging configuration and separation
> than possible with SL4J. For example one library could be configured
> to use a Logback SLF4J and another Log4j legacy SLF4J.
>  * If the library used to configured a down stream logging framework
> (ie logback) you might need interception (ie SubstituteLogger).
>
> Thoughts?
>
> I'm hoping perhaps the SL4J documentation recommend something like
> this for library writers.
>
> -Adam
>
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Adam Gent
Yes as noted in my not really javadoc comment:

/*
* Simply prefix Internal in front of LoggerFactory:
* So instead of:
* Logger logger = LoggerFactory.getLogger(MyClass.class);
* It should be:
* Logger logger = InternalLoggerFactory.getLogger(MyClass.class);
*/

Obviously this creates tight coupling with LoggerService but that is
OK because LoggerService is expected to be a copy and paste snippet
(that is each library should have its own namespace LoggerService). It
could also be multiple files. I just made it one file to encourage
easy copy and paste.

I use LoggerService in my own message bus library (it is a library
that is sort of like hystrix + guava eventbus + amqp + reactivestreams
that I plan on open sourcing someday). This library does it for
performance reasons.

I also have a configuration facade framework as well that has an
opensource start here https://github.com/agentgt/configfacade .  Our
internal version is far more sophisticated as well as actually
production quality and is the one that uses its own LoggerService as
well. This library does it for bootstrap reasons and to beat the
logging frameworks initialization.


I have seen other libraries that refuse to use SLF4J directly though
because of its static binding. Many JBoss libraries IIRC such as
RestEasy:  https://bill.burkecentral.com/2012/05/22/write-your-own-logging-abstraction/

Of course these libraries could have just wrapped the LogFactory
creation but instead implement their own logging wrapper which is a
lot more code as well as not implementing logging parameter
replacement at all or correctly ("{}").

-Adam

On Fri, Mar 17, 2017 at 4:36 PM, Ceki Gülcü <[hidden email]> wrote:

>
> Hi Adam,
>
> Using ServiceLoader.load(LoggerService.class) is quite a good idea. I think
> we will have to go that way in future versions of SLF4J to be compatible
> with Java 9.
>
> I suppose your library code no longer invokes
> org.slf4j.LoggerFactory.getLogger().  How do you use LoggerService in your
> libraries?
>
> On 3/17/2017 16:51, Adam Gent wrote:
>>
>> Many library writers want to use SLF4j but may want to avoid the
>> default initialization and binding process. In fact if it is a library
>> and not a framework I recommend something like what I'm proposing.
>>
>> I have written a single very small copy and paste class that you can
>> put in your own library to avoid default SLF4J initialization while
>> allowing consumers of your library to pick whatever SLF4J
>> initialization they like through the ServiceLoader mechanism. The
>> class is meant to be copied and pasted such that you pick your own
>> package (namespace) for the ServiceLoader part.
>>
>> The code is available at this github gist:
>>
>> https://gist.github.com/agentgt/28dc6e9724cb8b96ca08fc147476a7de
>>
>>
>> There are several reasons why if you are a library writer to consider
>> this pattern:
>>
>>  * Often library users don't want to see the annoying default missing
>> slf4 binding messages
>>  * Performance reasons. By defaulting to NOP you prevent accidental
>> performance problems by a user of the library.
>>  * You allow for even greater logging configuration and separation
>> than possible with SL4J. For example one library could be configured
>> to use a Logback SLF4J and another Log4j legacy SLF4J.
>>  * If the library used to configured a down stream logging framework
>> (ie logback) you might need interception (ie SubstituteLogger).
>>
>> Thoughts?
>>
>> I'm hoping perhaps the SL4J documentation recommend something like
>> this for library writers.
>>
>> -Adam
>>
> _______________________________________________
> slf4j-user mailing list
> [hidden email]
> 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
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Ceki Gulcu

Hi Adam,

--------------
Quoting from https://www.slf4j.org/faq.html#optional_dependency

It is reasonable to assume that in most projects Wombat will be one
dependency among many. If each library had its own logging wrapper, then
each wrapper would presumably need to be configured separately. Thus,
instead of having to deal with one logging framework, namely SLF4J, the
user of Wombat would have to detail with Wombat's logging wrapper as
well. The problem will be compounded by each framework that comes up
with its own wrapper in order to make SLF4J optional. (Configuring or
dealing with the intricacies of five different logging wrappers is not
exactly exciting nor endearing.)
--------------


--------------
Quoting from: http://stackoverflow.com/a/11360517/100970
and http://stackoverflow.com/a/11359358/100970

Except the end user could have already done this customization for his
own code, or another library that uses log4j or LogBack. jul is
extensible, but having to extend LogBack, jul, log4j and God only knows
which other logging framework because he uses 4 libraries that use 4
different logging frameworks is cumbersome. By using slf4j, you allow
him to configure the logging frameworks he wants. not the one you have
chosen. Remember that typical projects use myriads of libraries, and not
just yours.
--------------

You need to consider the Kantian argument. What will happen if every
library developer follows your pattern? In my opinion, the situation
will be not just bad but completely untenable for the end-user.

--
Ceki

On 3/17/2017 22:28, Adam Gent wrote:

> Yes as noted in my not really javadoc comment:
>
> /*
> * Simply prefix Internal in front of LoggerFactory:
> * So instead of:
> * Logger logger = LoggerFactory.getLogger(MyClass.class);
> * It should be:
> * Logger logger = InternalLoggerFactory.getLogger(MyClass.class);
> */
>
> Obviously this creates tight coupling with LoggerService but that is
> OK because LoggerService is expected to be a copy and paste snippet
> (that is each library should have its own namespace LoggerService). It
> could also be multiple files. I just made it one file to encourage
> easy copy and paste.
>
> I use LoggerService in my own message bus library (it is a library
> that is sort of like hystrix + guava eventbus + amqp + reactivestreams
> that I plan on open sourcing someday). This library does it for
> performance reasons.
>
> I also have a configuration facade framework as well that has an
> opensource start here https://github.com/agentgt/configfacade .  Our
> internal version is far more sophisticated as well as actually
> production quality and is the one that uses its own LoggerService as
> well. This library does it for bootstrap reasons and to beat the
> logging frameworks initialization.
>
>
> I have seen other libraries that refuse to use SLF4J directly though
> because of its static binding. Many JBoss libraries IIRC such as
> RestEasy:  https://bill.burkecentral.com/2012/05/22/write-your-own-logging-abstraction/
>
> Of course these libraries could have just wrapped the LogFactory
> creation but instead implement their own logging wrapper which is a
> lot more code as well as not implementing logging parameter
> replacement at all or correctly ("{}").
>
> -Adam
>
> On Fri, Mar 17, 2017 at 4:36 PM, Ceki Gülcü <[hidden email]> wrote:
>>
>> Hi Adam,
>>
>> Using ServiceLoader.load(LoggerService.class) is quite a good idea. I think
>> we will have to go that way in future versions of SLF4J to be compatible
>> with Java 9.
>>
>> I suppose your library code no longer invokes
>> org.slf4j.LoggerFactory.getLogger().  How do you use LoggerService in your
>> libraries?
>>
>> On 3/17/2017 16:51, Adam Gent wrote:
>>>
>>> Many library writers want to use SLF4j but may want to avoid the
>>> default initialization and binding process. In fact if it is a library
>>> and not a framework I recommend something like what I'm proposing.
>>>
>>> I have written a single very small copy and paste class that you can
>>> put in your own library to avoid default SLF4J initialization while
>>> allowing consumers of your library to pick whatever SLF4J
>>> initialization they like through the ServiceLoader mechanism. The
>>> class is meant to be copied and pasted such that you pick your own
>>> package (namespace) for the ServiceLoader part.
>>>
>>> The code is available at this github gist:
>>>
>>> https://gist.github.com/agentgt/28dc6e9724cb8b96ca08fc147476a7de
>>>
>>>
>>> There are several reasons why if you are a library writer to consider
>>> this pattern:
>>>
>>>  * Often library users don't want to see the annoying default missing
>>> slf4 binding messages
>>>  * Performance reasons. By defaulting to NOP you prevent accidental
>>> performance problems by a user of the library.
>>>  * You allow for even greater logging configuration and separation
>>> than possible with SL4J. For example one library could be configured
>>> to use a Logback SLF4J and another Log4j legacy SLF4J.
>>>  * If the library used to configured a down stream logging framework
>>> (ie logback) you might need interception (ie SubstituteLogger).
>>>
>>> Thoughts?
>>>
>>> I'm hoping perhaps the SL4J documentation recommend something like
>>> this for library writers.
>>>
>>> -Adam
>>>
>> _______________________________________________
>> slf4j-user mailing list
>> [hidden email]
>> http://mailman.qos.ch/mailman/listinfo/slf4j-user
>
>
>
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Adam Gent
Ceki,

Excellent points! I get little too idealistic on Fridays :).

The heart of issue is intercepting SL4J initialization and critical
control of a specific libraries logging.

This maybe solved in later versions of SLF4J through something like
the ServiceLoader (perhaps even an optional static method on
LoggerFactory.getLogger("LibraryName", Clazz<?>)) and then filter the
ServiceLoader LoggerFactory based on "LibraryName". But I worry that
may complicate SLF4J when most libraries and applications do not care
about initialization.

On the other hand for some reason many libraries really do need a
crosscutting filtering name as they do not use (or abuse) logger name
hierarchy correctly (usually the logger is something like HTTPOUT or
something ridiculous like that). Marker would be ideal for this but
for some reason Marker never really took off. So I could improve the
copy'n paste with a LoggingFactory that decorates all Loggers by
automatically passing a Marker representing the libraries name. Again
this would be just a recommendation for sophisticated libraries... not
all libraries.

The current wrapper I'm proposing for most libraries could (and
probably should) just do the default LoggerFactory.getLogger() and
probably not the NOPLoggerFactory().

Thus configuration would not change for most libraries (since they
would be doing the default LoggerFactory.getLogger()) and would allow
application developers to bootstrap initialization of logging for
libraries that are used for the bootstrap process.

Also while logback and other libraries do allow powerful filtering not
all libraries are new enough (e.g. log4j) and even then in some cases
the performance is still slower than a hard wired NOPLogger.

> You need to consider the Kantian argument. What will happen if every library developer follows your pattern? In my opinion, the situation will be not just bad but completely untenable for the end-user.

In hindsight I was embarrassingly overzealous about saying all
libraries should do this but for  sure there are several that
absolutely need to intercept SLF4J initialization or maybe logging is
only used for development of the library. Otherwise the writers of
these libraries go off and make their own crappy wrappers anyway and
use system properties to enable logging. Those wrappers are often far
worse than the SLF4J implementation code in slf4j-api and I think the
wrapper I'm proposing is a fair compromise to actually encourage
greater adoption of SLF4J particularly its API.


On Fri, Mar 17, 2017 at 6:47 PM, Ceki Gülcü <[hidden email]> wrote:

>
> Hi Adam,
>
> --------------
> Quoting from https://www.slf4j.org/faq.html#optional_dependency
>
> It is reasonable to assume that in most projects Wombat will be one
> dependency among many. If each library had its own logging wrapper, then
> each wrapper would presumably need to be configured separately. Thus,
> instead of having to deal with one logging framework, namely SLF4J, the user
> of Wombat would have to detail with Wombat's logging wrapper as well. The
> problem will be compounded by each framework that comes up with its own
> wrapper in order to make SLF4J optional. (Configuring or dealing with the
> intricacies of five different logging wrappers is not exactly exciting nor
> endearing.)
> --------------
>
>
> --------------
> Quoting from: http://stackoverflow.com/a/11360517/100970
> and http://stackoverflow.com/a/11359358/100970
>
> Except the end user could have already done this customization for his own
> code, or another library that uses log4j or LogBack. jul is extensible, but
> having to extend LogBack, jul, log4j and God only knows which other logging
> framework because he uses 4 libraries that use 4 different logging
> frameworks is cumbersome. By using slf4j, you allow him to configure the
> logging frameworks he wants. not the one you have chosen. Remember that
> typical projects use myriads of libraries, and not just yours.
> --------------
>
> You need to consider the Kantian argument. What will happen if every library
> developer follows your pattern? In my opinion, the situation will be not
> just bad but completely untenable for the end-user.
>
> --
> Ceki
>
> On 3/17/2017 22:28, Adam Gent wrote:
>>
>> Yes as noted in my not really javadoc comment:
>>
>> /*
>> * Simply prefix Internal in front of LoggerFactory:
>> * So instead of:
>> * Logger logger = LoggerFactory.getLogger(MyClass.class);
>> * It should be:
>> * Logger logger = InternalLoggerFactory.getLogger(MyClass.class);
>> */
>>
>> Obviously this creates tight coupling with LoggerService but that is
>> OK because LoggerService is expected to be a copy and paste snippet
>> (that is each library should have its own namespace LoggerService). It
>> could also be multiple files. I just made it one file to encourage
>> easy copy and paste.
>>
>> I use LoggerService in my own message bus library (it is a library
>> that is sort of like hystrix + guava eventbus + amqp + reactivestreams
>> that I plan on open sourcing someday). This library does it for
>> performance reasons.
>>
>> I also have a configuration facade framework as well that has an
>> opensource start here https://github.com/agentgt/configfacade .  Our
>> internal version is far more sophisticated as well as actually
>> production quality and is the one that uses its own LoggerService as
>> well. This library does it for bootstrap reasons and to beat the
>> logging frameworks initialization.
>>
>>
>> I have seen other libraries that refuse to use SLF4J directly though
>> because of its static binding. Many JBoss libraries IIRC such as
>> RestEasy:
>> https://bill.burkecentral.com/2012/05/22/write-your-own-logging-abstraction/
>>
>> Of course these libraries could have just wrapped the LogFactory
>> creation but instead implement their own logging wrapper which is a
>> lot more code as well as not implementing logging parameter
>> replacement at all or correctly ("{}").
>>
>> -Adam
>>
>> On Fri, Mar 17, 2017 at 4:36 PM, Ceki Gülcü <[hidden email]> wrote:
>>>
>>>
>>> Hi Adam,
>>>
>>> Using ServiceLoader.load(LoggerService.class) is quite a good idea. I
>>> think
>>> we will have to go that way in future versions of SLF4J to be compatible
>>> with Java 9.
>>>
>>> I suppose your library code no longer invokes
>>> org.slf4j.LoggerFactory.getLogger().  How do you use LoggerService in
>>> your
>>> libraries?
>>>
>>> On 3/17/2017 16:51, Adam Gent wrote:
>>>>
>>>>
>>>> Many library writers want to use SLF4j but may want to avoid the
>>>> default initialization and binding process. In fact if it is a library
>>>> and not a framework I recommend something like what I'm proposing.
>>>>
>>>> I have written a single very small copy and paste class that you can
>>>> put in your own library to avoid default SLF4J initialization while
>>>> allowing consumers of your library to pick whatever SLF4J
>>>> initialization they like through the ServiceLoader mechanism. The
>>>> class is meant to be copied and pasted such that you pick your own
>>>> package (namespace) for the ServiceLoader part.
>>>>
>>>> The code is available at this github gist:
>>>>
>>>> https://gist.github.com/agentgt/28dc6e9724cb8b96ca08fc147476a7de
>>>>
>>>>
>>>> There are several reasons why if you are a library writer to consider
>>>> this pattern:
>>>>
>>>>  * Often library users don't want to see the annoying default missing
>>>> slf4 binding messages
>>>>  * Performance reasons. By defaulting to NOP you prevent accidental
>>>> performance problems by a user of the library.
>>>>  * You allow for even greater logging configuration and separation
>>>> than possible with SL4J. For example one library could be configured
>>>> to use a Logback SLF4J and another Log4j legacy SLF4J.
>>>>  * If the library used to configured a down stream logging framework
>>>> (ie logback) you might need interception (ie SubstituteLogger).
>>>>
>>>> Thoughts?
>>>>
>>>> I'm hoping perhaps the SL4J documentation recommend something like
>>>> this for library writers.
>>>>
>>>> -Adam
>>>>
>>> _______________________________________________
>>> slf4j-user mailing list
>>> [hidden email]
>>> http://mailman.qos.ch/mailman/listinfo/slf4j-user
>>
>>
>>
>>
> _______________________________________________
> slf4j-user mailing list
> [hidden email]
> 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
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Adam Gent
In reply to this post by Ceki Gulcu
On Fri, Mar 17, 2017 at 6:47 PM, Ceki Gülcü <[hidden email]> wrote:

>
> Hi Adam,
>
> --------------
> Quoting from https://www.slf4j.org/faq.html#optional_dependency
>
> It is reasonable to assume that in most projects Wombat will be one
> dependency among many. If each library had its own logging wrapper, then
> each wrapper would presumably need to be configured separately. Thus,
> instead of having to deal with one logging framework, namely SLF4J, the user
> of Wombat would have to detail with Wombat's logging wrapper as well. The
> problem will be compounded by each framework that comes up with its own
> wrapper in order to make SLF4J optional. (Configuring or dealing with the
> intricacies of five different logging wrappers is not exactly exciting nor
> endearing.)
> --------------

Just to make my previous my points clear. My code (which is basically
just use your own static method instead of LoggerFactory.getLogger())
I'm proposing is to encourage users not to create their own wrappers
but write their on LoggerFactory.getLogger() instead of reimplementing
all of slf4j-api.

This is not to make SLF4J optional. The code is to disable or
intercept the static initialization of an API interface. I would
actually argue that an API should never do static initialization but
that ship has sailed. The framework or application should probably
explicitly initialize SLF4J but I admit the way SLF4J is currently
used and understood at this point it is probably easier. Consequently
Just know that the logging framework is almost always the first thing
to initialize (hence why one would really want to be configure it).

To show how egregious this is just putting an annotation on a class or
implementing an interface can cause of initialization of SLF4J which
then kicks off the initialization of the logging framework which may
or may not be configurable for interception.

>
>
> --------------
> Quoting from: http://stackoverflow.com/a/11360517/100970
> and http://stackoverflow.com/a/11359358/100970
>
> Except the end user could have already done this customization for his own
> code, or another library that uses log4j or LogBack. jul is extensible, but
> having to extend LogBack, jul, log4j and God only knows which other logging
> framework because he uses 4 libraries that use 4 different logging
> frameworks is cumbersome. By using slf4j, you allow him to configure the
> logging frameworks he wants. not the one you have chosen. Remember that
> typical projects use myriads of libraries, and not just yours.
> --------------
>

This is exactly my point. To control the initialization of our suite
of applications we have to write custom code that intercepts log4j,
log4j2, logback, etc all because there is no way to do it in SLF4J.
SLF4J is not configurable!

Why do we have all these different logging frameworks? Well because of
legacy code or that is what that application prefers (e.g. zookeeper
or solr or something). I'm talking in a microservice environment it is
actually common to have  a zoo of logging frameworks (obviously not in
the same app). I think you misunderstood me before and thought I meant
having all sorts of logging frameworks in the same application.

I guess ideally SLF4J should offer some sort of configuration (it
already has system.properties it reads to do things) to do what I'm
talking about but for the time being library writers can do what I'm
proposing particularly if logging isn't really a critical aspect of
the library.

Finally most libraries you do have to go look up information on how to
turn on logging for that particularly library. It is just a nasty fact
of life. Libraries don't use Markers or logger name hierarchy in a
standard way. Even then they still often (particularly for high
performance libraries) have some system property or something to
actually enable or disable logging.

I'm just trying to offer a best practice or standard to prevent the
above of every library being different or worse having a their own
complicated wrapper. Ideally SLF4J would offer more than just a best
practice.

>
> --
> Ceki
>
> On 3/17/2017 22:28, Adam Gent wrote:
>>
>> Yes as noted in my not really javadoc comment:
>>
>> /*
>> * Simply prefix Internal in front of LoggerFactory:
>> * So instead of:
>> * Logger logger = LoggerFactory.getLogger(MyClass.class);
>> * It should be:
>> * Logger logger = InternalLoggerFactory.getLogger(MyClass.class);
>> */
>>
>> Obviously this creates tight coupling with LoggerService but that is
>> OK because LoggerService is expected to be a copy and paste snippet
>> (that is each library should have its own namespace LoggerService). It
>> could also be multiple files. I just made it one file to encourage
>> easy copy and paste.
>>
>> I use LoggerService in my own message bus library (it is a library
>> that is sort of like hystrix + guava eventbus + amqp + reactivestreams
>> that I plan on open sourcing someday). This library does it for
>> performance reasons.
>>
>> I also have a configuration facade framework as well that has an
>> opensource start here https://github.com/agentgt/configfacade .  Our
>> internal version is far more sophisticated as well as actually
>> production quality and is the one that uses its own LoggerService as
>> well. This library does it for bootstrap reasons and to beat the
>> logging frameworks initialization.
>>
>>
>> I have seen other libraries that refuse to use SLF4J directly though
>> because of its static binding. Many JBoss libraries IIRC such as
>> RestEasy:
>> https://bill.burkecentral.com/2012/05/22/write-your-own-logging-abstraction/
>>
>> Of course these libraries could have just wrapped the LogFactory
>> creation but instead implement their own logging wrapper which is a
>> lot more code as well as not implementing logging parameter
>> replacement at all or correctly ("{}").
>>
>> -Adam
>>
>> On Fri, Mar 17, 2017 at 4:36 PM, Ceki Gülcü <[hidden email]> wrote:
>>>
>>>
>>> Hi Adam,
>>>
>>> Using ServiceLoader.load(LoggerService.class) is quite a good idea. I
>>> think
>>> we will have to go that way in future versions of SLF4J to be compatible
>>> with Java 9.
>>>
>>> I suppose your library code no longer invokes
>>> org.slf4j.LoggerFactory.getLogger().  How do you use LoggerService in
>>> your
>>> libraries?
>>>
>>> On 3/17/2017 16:51, Adam Gent wrote:
>>>>
>>>>
>>>> Many library writers want to use SLF4j but may want to avoid the
>>>> default initialization and binding process. In fact if it is a library
>>>> and not a framework I recommend something like what I'm proposing.
>>>>
>>>> I have written a single very small copy and paste class that you can
>>>> put in your own library to avoid default SLF4J initialization while
>>>> allowing consumers of your library to pick whatever SLF4J
>>>> initialization they like through the ServiceLoader mechanism. The
>>>> class is meant to be copied and pasted such that you pick your own
>>>> package (namespace) for the ServiceLoader part.
>>>>
>>>> The code is available at this github gist:
>>>>
>>>> https://gist.github.com/agentgt/28dc6e9724cb8b96ca08fc147476a7de
>>>>
>>>>
>>>> There are several reasons why if you are a library writer to consider
>>>> this pattern:
>>>>
>>>>  * Often library users don't want to see the annoying default missing
>>>> slf4 binding messages
>>>>  * Performance reasons. By defaulting to NOP you prevent accidental
>>>> performance problems by a user of the library.
>>>>  * You allow for even greater logging configuration and separation
>>>> than possible with SL4J. For example one library could be configured
>>>> to use a Logback SLF4J and another Log4j legacy SLF4J.
>>>>  * If the library used to configured a down stream logging framework
>>>> (ie logback) you might need interception (ie SubstituteLogger).
>>>>
>>>> Thoughts?
>>>>
>>>> I'm hoping perhaps the SL4J documentation recommend something like
>>>> this for library writers.
>>>>
>>>> -Adam
>>>>
>>> _______________________________________________
>>> slf4j-user mailing list
>>> [hidden email]
>>> http://mailman.qos.ch/mailman/listinfo/slf4j-user
>>
>>
>>
>>
> _______________________________________________
> slf4j-user mailing list
> [hidden email]
> 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
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Matt Sicker
The issue I've come across that's similar to this is integrating logging with Spring Boot or other initialization style frameworks. The issue there was that Spring Boot wants to defer logging initialization until it's loaded up enough of its own configuration related code, but that code also wants to use logging. Eager initialization of the logging system in Logback and Log4j both cause issues in these sorts of environments. In Log4j, we ended up using a similar pattern to the ServiceLoader files, but we added some additional metadata there like API version compatibility.

On 18 March 2017 at 10:18, Adam Gent <[hidden email]> wrote:
On Fri, Mar 17, 2017 at 6:47 PM, Ceki Gülcü <[hidden email]> wrote:
>
> Hi Adam,
>
> --------------
> Quoting from https://www.slf4j.org/faq.html#optional_dependency
>
> It is reasonable to assume that in most projects Wombat will be one
> dependency among many. If each library had its own logging wrapper, then
> each wrapper would presumably need to be configured separately. Thus,
> instead of having to deal with one logging framework, namely SLF4J, the user
> of Wombat would have to detail with Wombat's logging wrapper as well. The
> problem will be compounded by each framework that comes up with its own
> wrapper in order to make SLF4J optional. (Configuring or dealing with the
> intricacies of five different logging wrappers is not exactly exciting nor
> endearing.)
> --------------

Just to make my previous my points clear. My code (which is basically
just use your own static method instead of LoggerFactory.getLogger())
I'm proposing is to encourage users not to create their own wrappers
but write their on LoggerFactory.getLogger() instead of reimplementing
all of slf4j-api.

This is not to make SLF4J optional. The code is to disable or
intercept the static initialization of an API interface. I would
actually argue that an API should never do static initialization but
that ship has sailed. The framework or application should probably
explicitly initialize SLF4J but I admit the way SLF4J is currently
used and understood at this point it is probably easier. Consequently
Just know that the logging framework is almost always the first thing
to initialize (hence why one would really want to be configure it).

To show how egregious this is just putting an annotation on a class or
implementing an interface can cause of initialization of SLF4J which
then kicks off the initialization of the logging framework which may
or may not be configurable for interception.

>
>
> --------------
> Quoting from: http://stackoverflow.com/a/11360517/100970
> and http://stackoverflow.com/a/11359358/100970
>
> Except the end user could have already done this customization for his own
> code, or another library that uses log4j or LogBack. jul is extensible, but
> having to extend LogBack, jul, log4j and God only knows which other logging
> framework because he uses 4 libraries that use 4 different logging
> frameworks is cumbersome. By using slf4j, you allow him to configure the
> logging frameworks he wants. not the one you have chosen. Remember that
> typical projects use myriads of libraries, and not just yours.
> --------------
>

This is exactly my point. To control the initialization of our suite
of applications we have to write custom code that intercepts log4j,
log4j2, logback, etc all because there is no way to do it in SLF4J.
SLF4J is not configurable!

Why do we have all these different logging frameworks? Well because of
legacy code or that is what that application prefers (e.g. zookeeper
or solr or something). I'm talking in a microservice environment it is
actually common to have  a zoo of logging frameworks (obviously not in
the same app). I think you misunderstood me before and thought I meant
having all sorts of logging frameworks in the same application.

I guess ideally SLF4J should offer some sort of configuration (it
already has system.properties it reads to do things) to do what I'm
talking about but for the time being library writers can do what I'm
proposing particularly if logging isn't really a critical aspect of
the library.

Finally most libraries you do have to go look up information on how to
turn on logging for that particularly library. It is just a nasty fact
of life. Libraries don't use Markers or logger name hierarchy in a
standard way. Even then they still often (particularly for high
performance libraries) have some system property or something to
actually enable or disable logging.

I'm just trying to offer a best practice or standard to prevent the
above of every library being different or worse having a their own
complicated wrapper. Ideally SLF4J would offer more than just a best
practice.

>
> --
> Ceki
>
> On 3/17/2017 22:28, Adam Gent wrote:
>>
>> Yes as noted in my not really javadoc comment:
>>
>> /*
>> * Simply prefix Internal in front of LoggerFactory:
>> * So instead of:
>> * Logger logger = LoggerFactory.getLogger(MyClass.class);
>> * It should be:
>> * Logger logger = InternalLoggerFactory.getLogger(MyClass.class);
>> */
>>
>> Obviously this creates tight coupling with LoggerService but that is
>> OK because LoggerService is expected to be a copy and paste snippet
>> (that is each library should have its own namespace LoggerService). It
>> could also be multiple files. I just made it one file to encourage
>> easy copy and paste.
>>
>> I use LoggerService in my own message bus library (it is a library
>> that is sort of like hystrix + guava eventbus + amqp + reactivestreams
>> that I plan on open sourcing someday). This library does it for
>> performance reasons.
>>
>> I also have a configuration facade framework as well that has an
>> opensource start here https://github.com/agentgt/configfacade .  Our
>> internal version is far more sophisticated as well as actually
>> production quality and is the one that uses its own LoggerService as
>> well. This library does it for bootstrap reasons and to beat the
>> logging frameworks initialization.
>>
>>
>> I have seen other libraries that refuse to use SLF4J directly though
>> because of its static binding. Many JBoss libraries IIRC such as
>> RestEasy:
>> https://bill.burkecentral.com/2012/05/22/write-your-own-logging-abstraction/
>>
>> Of course these libraries could have just wrapped the LogFactory
>> creation but instead implement their own logging wrapper which is a
>> lot more code as well as not implementing logging parameter
>> replacement at all or correctly ("{}").
>>
>> -Adam
>>
>> On Fri, Mar 17, 2017 at 4:36 PM, Ceki Gülcü <[hidden email]> wrote:
>>>
>>>
>>> Hi Adam,
>>>
>>> Using ServiceLoader.load(LoggerService.class) is quite a good idea. I
>>> think
>>> we will have to go that way in future versions of SLF4J to be compatible
>>> with Java 9.
>>>
>>> I suppose your library code no longer invokes
>>> org.slf4j.LoggerFactory.getLogger().  How do you use LoggerService in
>>> your
>>> libraries?
>>>
>>> On 3/17/2017 16:51, Adam Gent wrote:
>>>>
>>>>
>>>> Many library writers want to use SLF4j but may want to avoid the
>>>> default initialization and binding process. In fact if it is a library
>>>> and not a framework I recommend something like what I'm proposing.
>>>>
>>>> I have written a single very small copy and paste class that you can
>>>> put in your own library to avoid default SLF4J initialization while
>>>> allowing consumers of your library to pick whatever SLF4J
>>>> initialization they like through the ServiceLoader mechanism. The
>>>> class is meant to be copied and pasted such that you pick your own
>>>> package (namespace) for the ServiceLoader part.
>>>>
>>>> The code is available at this github gist:
>>>>
>>>> https://gist.github.com/agentgt/28dc6e9724cb8b96ca08fc147476a7de
>>>>
>>>>
>>>> There are several reasons why if you are a library writer to consider
>>>> this pattern:
>>>>
>>>>  * Often library users don't want to see the annoying default missing
>>>> slf4 binding messages
>>>>  * Performance reasons. By defaulting to NOP you prevent accidental
>>>> performance problems by a user of the library.
>>>>  * You allow for even greater logging configuration and separation
>>>> than possible with SL4J. For example one library could be configured
>>>> to use a Logback SLF4J and another Log4j legacy SLF4J.
>>>>  * If the library used to configured a down stream logging framework
>>>> (ie logback) you might need interception (ie SubstituteLogger).
>>>>
>>>> Thoughts?
>>>>
>>>> I'm hoping perhaps the SL4J documentation recommend something like
>>>> this for library writers.
>>>>
>>>> -Adam
>>>>
>>> _______________________________________________
>>> slf4j-user mailing list
>>> [hidden email]
>>> http://mailman.qos.ch/mailman/listinfo/slf4j-user
>>
>>
>>
>>
> _______________________________________________
> slf4j-user mailing list
> [hidden email]
> http://mailman.qos.ch/mailman/listinfo/slf4j-user



--
CTO
SnapHop (snaphop.com)
(twitter) @agentgt (linkedin) http://www.linkedin.com/in/agentgt
(cell) <a href="tel:781-883-5182" value="+17818835182">781-883-5182
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user



--
Matt Sicker <[hidden email]>

_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Joachim Durchholz
In reply to this post by Adam Gent
Am 17.03.2017 um 16:51 schrieb Adam Gent:
> Many library writers want to use SLF4j but may want to avoid the
> default initialization and binding process.

Actually that is the decision of the main program to make.
Libraries should simply send their log messages to SLF4J and let it
report or ignore them.

That's why I still don't really understand what you're trying to achieve.
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

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.

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 (You
could do with with the SubstituteLogger to retain events IIRC).

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).

> That's why I still don't really understand what you're trying to achieve.

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).

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.

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).

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.

Of course you could standardize this in SLF4J with perhaps some sort
two phase approach but then you complicate SLF4J.

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.


On Sat, Mar 18, 2017 at 11:52 AM, Joachim Durchholz <[hidden email]> wrote:

> Am 17.03.2017 um 16:51 schrieb Adam Gent:
>>
>> Many library writers want to use SLF4j but may want to avoid the
>> default initialization and binding process.
>
>
> Actually that is the decision of the main program to make.
> Libraries should simply send their log messages to SLF4J and let it report
> or ignore them.
>
> That's why I still don't really understand what you're trying to achieve.
> _______________________________________________
> slf4j-user mailing list
> [hidden email]
> 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
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Joachim Durchholz
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
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: 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 <[hidden email]> 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
> [hidden email]
> 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
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Ceki Gulcu


On 3/18/2017 20:04, Adam Gent wrote:

[snip]

> 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.

That's just a warning message. SLF4J could drop that warning. The user
would be oblivious to why logging is not working but otherwise things
would just be ticking.

> 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

Logging needs to be set up somehow. SLF4J has adopted the most stupid
approach imaginable for selecting the logging backend. The main
advantage of this stupid approach is that it is easy to understand to
anyone interested.

>> 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.

There is a little android related optimization in
org.slf4j.LoggerFactory during initialization which was introduced a few
months back.

>>
>> 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).

I somehow doubt that. NOPLogger does nothing, so invoking it costs a
method call. Getting a NOPLogger involves reading the value of
INITIALIZATION_STATE which is a volatile int. Unless reading volatile
variables is expensive in Android, there is really no way to optimize
logging with SLF4J+NOPLogger.

>> 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.

Why do you think you need your own interception? In multi-threaded
boot-up process, SLF4J event replay just works. It's an internal process
transparent to user code. In a single threaded boot-up, event replay
works just as well. The interception is done by SLF4J while the logging
back end is configuring itself and the intercepted events are replayed
after the logging backed has finished configuring itself.

--
Ceki
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Adam Gent
On Sat, Mar 18, 2017 at 3:45 PM, Ceki Gülcü <[hidden email]> wrote:

> Logging needs to be set up somehow. SLF4J has adopted the most stupid
> approach imaginable for selecting the logging backend. The main advantage of
> this stupid approach is that it is easy to understand to anyone interested.

I agree. Again this would be for those that for some reason that don't
want to ship with any possible output caused by their library.
Probably a fringe case. Just to be clear I wasn't a strong proponent
but I wanted to play devils advocate for those that still would prefer
zero side effects.

>
> I somehow doubt that. NOPLogger does nothing, so invoking it costs a method
> call. Getting a NOPLogger involves reading the value of INITIALIZATION_STATE
> which is a volatile int. Unless reading volatile variables is expensive in
> Android, there is really no way to optimize logging with SLF4J+NOPLogger.
>

That is my point. The NOPLogger does nothing. It is what the library
would be picking as the default instead of relying on the backend
logger code (which requires initialization and overhead for filter).
Now if they have the NOP backend (which is different than the NOP
logger) that is different story but most are using logback or log4j2
these days.

If the library used Logging.getLogger() and used the backend logger
you would not get a NOPLogger. Most backend logging frameworks aren't
going to somehow know selectively to defer to the NOPLogger (or
equivalent NOP action) with out performing some logic. That is they
still have to perform logic whether to emit the trace messages or not.

I mean I generally agree my arguments are fairly weak because I'm
defending a small minority of libraries. That is part because
libraries that have these problems (chicken/egg, performance issues)
just avoid logging all together or write their own (e.g.
https://github.com/EsotericSoftware/kryo has its own).

>
> Why do you think you need your own interception? In multi-threaded boot-up
> process, SLF4J event replay just works. It's an internal process transparent
> to user code. In a single threaded boot-up, event replay works just as well.
> The interception is done by SLF4J while the logging back end is configuring
> itself and the intercepted events are replayed after the logging backed has
> finished configuring itself.
>

Because you now have to put all your initialization configuration
(like calling discovery services like zookeeper or consul) in the
backend logging framework and this is because the logging framework
almost always runs first unless you are extremely judicious about what
libraries you use to setup your application.

The real issue is you may need to configure the backend logging framework.

And this hard because we are in a cloud world where yeah you have to
connect a whole bunch of things to get configuration and those clients
need to do logging. This is a real problem that both dropwizard and
spring know about.

Yeah can customize your logging backend to run some code first but
this was and still sort of difficult (if you remember I was the one
who did the implementation for the ServiceLoader for logback).

And yeah you could just reinitialize the logging framework but not all
frameworks support that (well).

Yeah you could just write a custom SLF4J adapter for the library but
this is actually impossible for some libraries that natively speak
SLF4J.

Maybe others just don't run into these issues because they do file
based logging. We push the logs over the network to a queue. We prefer
this over the pull method but I guess  that is one major advantage of
the pull method (not having to configure the logger).




> --
> Ceki
> _______________________________________________
> slf4j-user mailing list
> [hidden email]
> 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
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Ceki Gulcu


On 3/18/2017 21:26, Adam Gent wrote:

> Because you now have to put all your initialization configuration
> (like calling discovery services like zookeeper or consul) in the
> backend logging framework and this is because the logging framework
> almost always runs first unless you are extremely judicious about what
> libraries you use to setup your application.
>
> The real issue is you may need to configure the backend logging framework.
>
> And this hard because we are in a cloud world where yeah you have to
> connect a whole bunch of things to get configuration and those clients
> need to do logging. This is a real problem that both dropwizard and
> spring know about.


I don't follow you. Can you give simplified example of the chicken and
egg problem? Do you mean for example logback configuration which has as
DBAppender writing to a database with a JDBC connector which itself uses
slf4j for logging? This should work with the aforementioned event replay
mechanism. Any other examples?

--
Ceki

_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Adam Gent
On Sat, Mar 18, 2017 at 4:50 PM, Ceki Gülcü <[hidden email]> wrote:

>
>
> On 3/18/2017 21:26, Adam Gent wrote:
>
>> Because you now have to put all your initialization configuration
>> (like calling discovery services like zookeeper or consul) in the
>> backend logging framework and this is because the logging framework
>> almost always runs first unless you are extremely judicious about what
>> libraries you use to setup your application.
>>
>> The real issue is you may need to configure the backend logging framework.
>>
>> And this hard because we are in a cloud world where yeah you have to
>> connect a whole bunch of things to get configuration and those clients
>> need to do logging. This is a real problem that both dropwizard and
>> spring know about.
>
>
>
> I don't follow you. Can you give simplified example of the chicken and egg
> problem? Do you mean for example logback configuration which has as
> DBAppender writing to a database with a JDBC connector which itself uses
> slf4j for logging? This should work with the aforementioned event replay
> mechanism. Any other examples?

How do get the connection string for the DBAppender?
In traditional environments people used system properties or
environment variables but today people connect to other remote systems
to get configuration. Some examples are Zookeeper, Consul, etcd,
Google Cloud Metadata.

So I either need to write code that executes before the logging
backend to setup the environment. If the clients to the metadata
services kick off logging then logging will be configured incorrectly
(lets assume no reinitialization or substitute loggers).

To prevent this I could of course make an omniscient DBAppender that
gets the configuration (and then the log replay system would work) but
this requires me knowing about the underlying logging framework (and
writing a special appender for backend).

I actually did the appender route for awhile but I had various issues
particularly with old log4j and an older logback that didn't have
replay (or maybe it was reentry.. I can't recall). I also just prefer
having our code run first instead of the logging framework.

So what we do now is just use custom configuration and client
libraries that do absolutely zero logging making sure to run this code
before any other code that kicks off logging. However in some
environments despite what Joachim thinks this is nontrivial in say a
servlet environment or using Spring Boot because those guys have some
sort of static reference somewhere with getLogger.


--
CTO
SnapHop (snaphop.com)
(twitter) @agentgt (linkedin) http://www.linkedin.com/in/agentgt
(cell) 781-883-5182
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Joachim Durchholz
In reply to this post by Ceki Gulcu
Am 18.03.2017 um 20:45 schrieb Ceki Gülcü:
 > Getting a NOPLogger involves reading the value of
> INITIALIZATION_STATE which is a volatile int. Unless reading volatile
> variables is expensive in Android,

They can be.

If the CPU has first-level caches that are not shared between all cores,
then it can happen that the value gets read into two caches, then
updated in one cache.
Smart cores keep track of what addresses are currently in other cores'
caches, and if they update a value, they first ask the other cores to
evict the cached address, so the standard case (shared data is mostly
just read) can run at full speed.
Dumb cores need a lock instruction, causing the core to pull any updated
value from other cores' caches.

Smart JVM implementors, coding the JVM in C, will find out whether the
CPU they are porting the JVM to is smart or dumb, and generate a lock
instruction if the CPU is dumb - or if they don't know what they're
doing, or if they cannot be sure because a few CPU batches had bugs in
their cache implementation, or if they cannot be sure because they
aren't given enough time to properly test everything.

If you can make SLF4J's initialization idempotent, i.e. running it twice
doesn't matter, then you can keep the "initialized" status in a normal
variable. The update from "not initialized" to "initialized" may not
already be set for all threads, so multiple threads may run the
initialization, and one of them may overwrite the other's result, but
that doesn't matter...

The other option would be to forfeit laziness and do all SLF4J
initialization in class initialization code, i.e. inside of static{} blocks.
The JVM semantics guarantees that static{} code is executed once and
exactly once, which is exactly what's needed.
Of course the "initialized" flag is still present, it's just in the
class data of the JVM - however, since class loading is so important,
this is going to be the most-optimized code path.
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Joachim Durchholz
In reply to this post by Adam Gent
Am 18.03.2017 um 21:26 schrieb Adam Gent:
> I mean I generally agree my arguments are fairly weak because I'm
> defending a small minority of libraries. That is part because
> libraries that have these problems (chicken/egg, performance issues)

I still need to see how these problems even exist.

> just avoid logging all together or write their own (e.g.
> https://github.com/EsotericSoftware/kryo has its own).

Kryo does its own logging not due to chicken/egg problems but because
Nathan believes the complexity of an extra logger implementation is
totally worth it if you can optimize out the logger.trace calls statically.
It's a minority position, and one that I don't share because if we
really start to count function calls then Java isn't the right tool for
the job anyway.
What happened is that people stopped arguing with Nathan and started
writing an SLF4J adapter for Kryo, which seems to be working fine.
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Adam Gent
In reply to this post by Adam Gent
I guess to simplify what I'm saying is you could of course do the
configuration lookup (or bootstrap) in your backend logging framework
which will work thanks to the event replay. The problem is that it is
awkward to do most of your initialization in the logging framework let
alone something so specific like an Appender .

Imagine explaining to other developers... oh yeah our initialization
code that setups singleton metadata (like environment info such as
region and various other cloud metadata)... the DBAppender makes the
first call to it. Its confusing to follow just like it is confusing to
configure who initialized the logging framework first (well with a
debugger it isn't but whatever).

But yeah I'm not really making any strong points one way or the other.
I mean it isn't pretty but you can get buy and I'm not sure how SLF4J
at this time really could help (that is as much as I hate its simple
static initialization it is to your point the right way).


On Sat, Mar 18, 2017 at 5:06 PM, Adam Gent <[hidden email]> wrote:

> On Sat, Mar 18, 2017 at 4:50 PM, Ceki Gülcü <[hidden email]> wrote:
>>
>>
>> On 3/18/2017 21:26, Adam Gent wrote:
>>
>>> Because you now have to put all your initialization configuration
>>> (like calling discovery services like zookeeper or consul) in the
>>> backend logging framework and this is because the logging framework
>>> almost always runs first unless you are extremely judicious about what
>>> libraries you use to setup your application.
>>>
>>> The real issue is you may need to configure the backend logging framework.
>>>
>>> And this hard because we are in a cloud world where yeah you have to
>>> connect a whole bunch of things to get configuration and those clients
>>> need to do logging. This is a real problem that both dropwizard and
>>> spring know about.
>>
>>
>>
>> I don't follow you. Can you give simplified example of the chicken and egg
>> problem? Do you mean for example logback configuration which has as
>> DBAppender writing to a database with a JDBC connector which itself uses
>> slf4j for logging? This should work with the aforementioned event replay
>> mechanism. Any other examples?
>
> How do get the connection string for the DBAppender?
> In traditional environments people used system properties or
> environment variables but today people connect to other remote systems
> to get configuration. Some examples are Zookeeper, Consul, etcd,
> Google Cloud Metadata.
>
> So I either need to write code that executes before the logging
> backend to setup the environment. If the clients to the metadata
> services kick off logging then logging will be configured incorrectly
> (lets assume no reinitialization or substitute loggers).
>
> To prevent this I could of course make an omniscient DBAppender that
> gets the configuration (and then the log replay system would work) but
> this requires me knowing about the underlying logging framework (and
> writing a special appender for backend).
>
> I actually did the appender route for awhile but I had various issues
> particularly with old log4j and an older logback that didn't have
> replay (or maybe it was reentry.. I can't recall). I also just prefer
> having our code run first instead of the logging framework.
>
> So what we do now is just use custom configuration and client
> libraries that do absolutely zero logging making sure to run this code
> before any other code that kicks off logging. However in some
> environments despite what Joachim thinks this is nontrivial in say a
> servlet environment or using Spring Boot because those guys have some
> sort of static reference somewhere with getLogger.
>
>
> --
> CTO
> SnapHop (snaphop.com)
> (twitter) @agentgt (linkedin) http://www.linkedin.com/in/agentgt
> (cell) 781-883-5182



--
CTO
SnapHop (snaphop.com)
(twitter) @agentgt (linkedin) http://www.linkedin.com/in/agentgt
(cell) 781-883-5182
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Recommendation for library writers: use thiscopy and paste wrapper around SLF4j to avoid default static initialization

Adam Gent
In reply to this post by Joachim Durchholz
I concede on the performance. It is been a while since I have
attempted micro benchmarks particularly with the modern logging
backends. Its also not my area of expertise.

But the chicken/egg problem is real albeit solvable particularly with
more powerful logging backends.

My little wrapper proposition seems like a pretty crappy idea now...
oh well. It did help us with some issues (chicken/egg and some fringe
case unit testing issues).



On Sat, Mar 18, 2017 at 5:17 PM, Joachim Durchholz <[hidden email]> wrote:

> Am 18.03.2017 um 21:26 schrieb Adam Gent:
>>
>> I mean I generally agree my arguments are fairly weak because I'm
>> defending a small minority of libraries. That is part because
>> libraries that have these problems (chicken/egg, performance issues)
>
>
> I still need to see how these problems even exist.
>
>> just avoid logging all together or write their own (e.g.
>> https://github.com/EsotericSoftware/kryo has its own).
>
>
> Kryo does its own logging not due to chicken/egg problems but because Nathan
> believes the complexity of an extra logger implementation is totally worth
> it if you can optimize out the logger.trace calls statically.
> It's a minority position, and one that I don't share because if we really
> start to count function calls then Java isn't the right tool for the job
> anyway.
> What happened is that people stopped arguing with Nathan and started writing
> an SLF4J adapter for Kryo, which seems to be working fine.
> _______________________________________________
> slf4j-user mailing list
> [hidden email]
> 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
_______________________________________________
slf4j-user mailing list
[hidden email]
http://mailman.qos.ch/mailman/listinfo/slf4j-user
12
Loading...