CODEWITHSUNDEEP
javajakarta-eelogback
Andy Dufresne
Andy Dufresne

Reputation: 6180

Logback defaulting to debug mode for some third party libraries

We use slf4j and logback for logging in our java ee web application. Recently in order to move these libraries to a common location in the glassfish app server (to glassfish\lib directory specifically) we made a couple of configuration changes. We made changes in the web.xml file to add JNDI entries and renamed the logback.xml to logback-<context-name>.xml as specified in here. The logback-<context-name>.xml is placed in WEB-INF\classes directory.

After this change, logging for hibernate and http-client libraries is defaulting to debug mode and hence there is lot of logging being done. The root logger has INFO log level and there are no specific loggers defined for hibernate & http-client libraries.

If I revert this change i.e. remove the jndi entry in web.xml and rename the configuration file to logback.xml, only INFO logs are logged as expected.

Any suggestions on what could be the issue?

Thanks.

Update

On troubleshooting further I released that hibernate and apache client libraries use the default logger context created during the initialization time. This logger context has the root log level set to DEBUG. We use JNDI as the context selector.

It is strange that the context name is not found at runtime when the ConnectionManager class (hibernate class - org.hibernate.jdbc.ConnectionManager) tries to instantiate a logger. Logger instance creation calls ContextJNDISelector.getLoggerContext() method. This method does a JNDI lookup but does not find the entry.

I troubleshooted further by spawning a thread in a servlet context listener to print the JNDI entry (java:comp/env/logback/context-name) every 3 seconds. The logs from the thread indicate that the JNDI entries are always present.

Any ideas why is contextName is not found in JNDI when queried by ContextJNDISelector?

Upvotes: 2

Views: 1115

Answers (1)

Andy Dufresne
Andy Dufresne

Reputation: 6180

This seemed to be a problem because the application used EJB's. The application server (glassfish) loaded the EJB's before the logging context was actually set. Hence the log messages for some of the libraries got logged under DEBUG level. Using a wrapper class around the logger resolved the issue. The wrapper class delayed the logger creation until its first use.


public class LogWrapper {
    private Class loggerClass;
    private Logger logger;

    public LogWrapper(Class loggerClass) {
        this.loggerClass = loggerClass; //lazy logging context creation (to avoid issues with static instances in EJBs which get loaded on startup before logging ctx name is actually set)
    }

    /**
     * For lazy init of logger, on first actual use, so the logger context will be correctly set even when used by EJBs (loaded by classloader too soon, before logging context is actually set)
     */
    private Logger getLogger() {
        if (logger == null) {
            logger = LoggerFactory.getLogger(loggerClass);
            loggerClass = null;
        }
        return logger;
    }

    public void info(String message) {
        getLogger().info(message);
    }

Upvotes: 0

Related Questions