SLF4J initializes when using rocker as annotation code generator

[agentgt]

We are using the Rocker template engine as an Annotation Code Generator (apt) which causes minor log error noise to actual serious serious break the compiler problems because SLF4J does static initialization.

This happens because the maven compiler plugin (and I believe stock javac) does annotation processing using the classpath of the code to be compiled.....

Thus if the code to be compiled has any logging configuration and/or logging libraries that implement SLF4J the compiler will kick off the logger that is configured in the code to be compiled. I don't think a compiler should do that.

Anyway I recommend copying this gist somewhere in rocker-runtime which makes it so that SLF4J does not kick off its static initialization: https://gist.github.com/agentgt/28dc6e9724cb8b96ca08fc147476a7de

Then in your rocker-runtime code base you just follow these directions (obviously with corrected imports to the custom gist class).

    /*
     * 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);
     */

I have long argued with @ceki et al about this so if I seem frustrated its because its like the upteenth time I have ran into random logging issues because of static initialization in various libraries. Also I'm frankly tired of fighting this battle but unfortunately have to or otherwise fork rocker or use a different templating library.

If you want rocker to have logging on by default you can make another library/module as a default dependency say rocker-slf4j and have it implement LoggerService using the ServiceLocator pattern.

As pro the above will also improve performance for those that do not care to have their templating library doing logging (even if it doesn't output its still accessing the logging framework). I think this library fits that because it is sort of high performance.

Anyway let me know if you want me to do a pull request.

[jjlauer]

Hey Adam,

Thanks for the helpful explanation. I've never ran into this issue, but I follow what you're saying.

So you'd like to copy 'n paste that gist as a new utility class we include with Rocker. Then switch any calls to LoggerFactory. to use the new InternalLoggerFactory.

I'm game for this to be a PR. I'll be interested in see it in action.

Joe

On Thu, May 2, 2019 at 3:39 PM Adam Gent notifications@github.com wrote:

We are using the Rocker template engine as an Annotation Code Generator (apt) which causes minor log error noise to actual serious serious break the compiler problems because SLF4J does static initialization.

This happens because the maven compiler plugin (and I believe stock javac) does annotation processing using the classpath of the code to be compiled.....

Thus if the code to be compiled has any logging configuration and/or logging libraries that implement SLF4J the compiler will kick off the logger that is configured in the code to be compiled. I don't think a compiler should do that.

Anyway I recommend copying this gist somewhere in rocker-runtime which makes it so that SLF4J does not kick off its static initialization: https://gist.github.com/agentgt/28dc6e9724cb8b96ca08fc147476a7de

Then in your rocker-runtime code base you just follow these directions (obviously with corrected imports to the custom gist class).

/*

• 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); */

I have long argued with @ceki et al http://slf4j.42922.n3.nabble.com/Recommendation-for-library-writers-use-thiscopy-and-paste-wrapper-around-SLF4j-to-avoid-default-statn-tc4026644.html#none about this so if I seem frustrated its because its like the upteenth time I have ran into random logging issues because of static initialization in various libraries. Also I'm frankly tired of fighting this battle but unfortunately have to or otherwise fork rocker or use a different templating library.

If you want rocker to have logging on by default you can make another library/module as a default dependency say rocker-slf4j and have it implement LoggerService using the ServiceLocator pattern.

As pro the above will also improve performance for those that do not care to have their templating library doing logging (even if it doesn't output its still accessing the logging framework). I think this library fits that because it is sort of high performance.

Anyway let me know if you want me to do a pull request.

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/fizzed/rocker/issues/106, or mute the thread https://github.com/notifications/unsubscribe-auth/AAEPAAWPZNMFZOEXM22KQ2DPTM7N7ANCNFSM4HKFVTEQ .

[agentgt]

Oh it looks like RockerRuntime is the only place logging is done and there are only like 3 calls.... so maybe there is a simpler solution.

[agentgt]

I'm thinking maybe we could just check if rocker-compiler is in the classpath and then use slf4j but that still requires some wrapper. I'll try to come up with something least disruptive.

EDIT basically the idea is if they are using reloading than using logging is OK (ie rocker-compiler). It looks like there is already some bootstrapping going on anyway in the exact place where the logging is happening (RockerRuntime).

[ceki]

@agentgt SLF4J 1.8 and 2.0 use ServiceLoader. Will this solve the issue your are raising?

[agentgt]

@ceki maybe. I'll have to test but my gut is no because the issue is if the library to be compiled is using the ServiceLoader I think you run into the same problems. I think some libraries just need another level of configuration to turn on logging.

EDIT it depends on how the ServiceLoader config is generated. Ironically this is why many use Google Auto Service so that the annotation generator doesn't pick up the ServiceLoader for your own annotation processor.

[agentgt]

@jjlauer Let me know what you think of the fix. If it looks good I can squash the commits.

[agentgt]

@agentgt SLF4J 1.8 and 2.0 use ServiceLoader. Will this solve the issue your are raising?

@ceki I think the new SLF4J that uses the ServiceLoader will work if I shade the library and I put my own SLF4JServiceProvider in my annotation processor.

This will work because the LoggerFactory first does:

ServiceLoader<SLF4JServiceProvider> serviceLoader = ServiceLoader.load(SLF4JServiceProvider.class);

When shaded the SLF4JServiceProvider.class will have a different namespace and thus not load providers in the code being compiled.

However this will not work for SLF4Js that do not have the service provider mechanism (ie 1.7 which is what Rocker has a dependency on) because of this in the LoggerFactory:

// We need to use the name of the StaticLoggerBinder class, but we can't
// reference the class itself.
private static String STATIC_LOGGER_BINDER_PATH = "org/slf4j/impl/StaticLoggerBinder.class";

The shader doesn't know to change STATIC_LOGGER_BINDER_PATH.

Anyway I think the new SLF4J is a great step in the right direction!

Sort of off topic for this thread but I still think way too many low level libraries depend on SLF4J for trivial logging (perfect example here since rocker only calls log.info 3 times). I think if logging like behavior is important to these libraries they should either provide callbacks/hooks for info like events, throw exceptions on error (instead of logging to error) or just make the logging configurable since its probably for diagnostics.

I know its been argued "if all libraries make an extra step for logging...." we will end up worse then before SLF4J but I think this is hardly true considering I'm only recommending this for low level libraries and not some framework (e.g. Spring). Also end users still have to go look at what packages a project uses anyway (ie crack open code) or the library documentation and thus is not that much of a burden on end users for one extra step to turn on SLF4J for a specific library (after that everything else is the same anyway).

[agentgt]

@ceki Since I'm shading the annotation processor now I can use any slf4j I want to so I picked 1.8 beta which uses the ServiceLoader and I got it to work with one major caveat.

The annotation processor does not bind a ClassLoader to the thread that will load resources. I have no idea why this is but I have a workaround that I posted on StackOverflow .

Basically the gist is you need to do this:

Thread.currentThread().setContextClassLoader(getClass().getClassLoader());

Before calling LoggerFactory.getLogger(...) so that the ServiceLoader gets the right ClassLoader. BTW as a side note it would be nice if the slf4j warning report caused by not finding a binding via Util.report reported the version of slf4j that is having problems. Shall I file a feature request for that?

Anyway I now I have my own shaded slf4j (ie different namespace) in my annotation processor and it works well.

Thus @jjlauer I don't need this fixed now but I still feel that rocker-runtime would be best without a slf4j dependency particularly given how little it is used.

Most of the logging is done with rocker-compiler and I'm completely fine with that.