Tuesday, January 11, 2011

JDK Logging per Webapp

Logging in Java is probably the easier thing that has been made a lot complicated. In Java, you have plenty of logging libraries and wrappers amongst:
  • commons logging
  • log4j, log4j extras, jmx, mail
  • slf4j (api, implementation, commons logging wrapper, jdk logging wrapper, ...)
  • jdk logging (java.util.logging)
  • and a lot and lot of others
You aim to have in your web application at then end all of these stupid wrappers because libraries depends on them.
If you are concerned about performance, you already know that the best way to use those loggers are by testing then logging:

private static final Logger LOGGER = Logger.getLogger(MyClass.class.getName());
[...]
if (LOGGER.isLoggable(Level.FINE))
    LOGGER.fine("Creating new connection...");

My frustration when I see libraries and applications developed is always the same: You are provided by the JDK with a common logging system available to anyone without the need of any external JAR. You also write the same code when you want to log something.

So why the hell are people keep using libraries like SLF4J or commons-logging or even more !!!!

The JDK logging API, even if not as good as log4j, does everything you need. A shortcoming was that the JDK logging system is not well designed to work in an application server and have each web application controlling its own logging configuration. This is mainly due to the fact that java.* classes are directly loaded from the system classloader.

But this is not the case anymore !!!

I've written a very small JAR which you can put in your application server common libraries. This JAR enables your web applications to use the JDK logging system and have each different configurations.

You will find all information here: http://code.google.com/p/mycila/wiki/JdkLoggingPerWebapp

So now your don't need to use any logging wrapper anymore !! Just use the standard JDK Logging API.

But wait !!!

You can now develop libraries and code completely independent of any logging libraries. But what if someone wants to use the JDK API but still want to output logs with log4j (log rotation, compression, ...) ?

Writing a wrapper for the JDK Logging system is trivial ! Here is one that can redirect all JDK logging calls to log4j:

import org.apache.log4j.Level;
import org.apache.log4j.Logger;

import java.util.HashMap;
import java.util.Map;
import java.util.logging.Handler;
import java.util.logging.LogManager;
import java.util.logging.LogRecord;

/**
 * @author Mathieu Carbou
 */
public final class JdkOverLog4j extends Handler {

    private static final Map<java.util.logging.Level, Level> LEVELS_JDK_TO_LOG4J = new HashMap<java.util.logging.Level, Level>() {
        {
            put(java.util.logging.Level.OFF, Level.OFF);
            put(java.util.logging.Level.SEVERE, Level.ERROR);
            put(java.util.logging.Level.WARNING, Level.WARN);
            put(java.util.logging.Level.INFO, Level.INFO);
            put(java.util.logging.Level.CONFIG, Level.INFO);
            put(java.util.logging.Level.FINE, Level.DEBUG);
            put(java.util.logging.Level.FINER, Level.DEBUG);
            put(java.util.logging.Level.FINEST, Level.DEBUG);
            put(java.util.logging.Level.ALL, Level.ALL);
        }
    };

    private static final Map<Level, java.util.logging.Level> LEVELS_LOG4J_TO_JDK = new HashMap<Level, java.util.logging.Level>() {
        {
            put(Level.OFF, java.util.logging.Level.OFF);
            put(Level.FATAL, java.util.logging.Level.SEVERE);
            put(Level.ERROR, java.util.logging.Level.SEVERE);
            put(Level.WARN, java.util.logging.Level.WARNING);
            put(Level.INFO, java.util.logging.Level.INFO);
            put(Level.DEBUG, java.util.logging.Level.FINE);
            put(Level.TRACE, java.util.logging.Level.FINE);
            put(Level.ALL, java.util.logging.Level.ALL);
        }
    };

    @Override
    public void publish(LogRecord record) {
        // normalize levels
        Logger log4jLogger = Logger.getLogger(record.getLoggerName());
        Level log4jLevel = log4jLogger.getEffectiveLevel();
        java.util.logging.Logger jdkLogger = java.util.logging.Logger.getLogger(record.getLoggerName());
        java.util.logging.Level expectedJdkLevel = LEVELS_LOG4J_TO_JDK.get(log4jLevel);
        if (expectedJdkLevel == null)
            throw new AssertionError("Level not supported yet - have a bug !" + log4jLevel);
        if (!expectedJdkLevel.equals(jdkLogger.getLevel())) {
            jdkLogger.setLevel(expectedJdkLevel);
        }
        log4jLogger.log(record.getLoggerName(), LEVELS_JDK_TO_LOG4J.get(record.getLevel()), record.getMessage(), record.getThrown());
    }

    @Override
    public void flush() {
    }

    @Override
    public void close() throws SecurityException {
    }

    public static void install() {
        LogManager.getLogManager().reset();
        LogManager.getLogManager().getLogger("").addHandler(new JdkOverLog4j());
        LogManager.getLogManager().getLogger("").setLevel(java.util.logging.Level.ALL);
    }
}

Simply put this class in your webapp and at the startup of your webapp, run the code:

JdkOverLog4j.install();

Now all calls to the JDK Logging system are redirected to Log4j !!!

So now you have the best of both world:
  • You are using the standard java.util.logging API
  • You are not binding your code to any logging library or wrapper
  • The client can decide which system he will use
  • You can still use log4j at the very end, but your application and libraries will be even more loosely coupled to it

18 comments:

  1. "But what if someone wants to use the JDK API but still want to output logs with log4j"

    That's *exactly* why people use SLF4J. That's what it does.

    ReplyDelete
  2. Yes but this choice should be up to the end application.

    A library should not rely on an external dependency for its internal logging usage, because it forces the client of this library to also use SLF4J. When using the JDK logging API, you don't bother the client with your internal details of logging, you still provides the client the choice to use JDK as a logging system or redirect calls to another system, like he want.

    I'm not against using SLF4J in END APPLICATION but i'm against using commons-logging or SLF4j or any other wrapper in libraries.

    See http://tinyurl.com/4efrp29 for other explanations...

    ReplyDelete
  3. Can we use rolling file appenders and filtered logs (different log files for different log levels) with java.util.logging API?

    java.util.logging

    ReplyDelete
  4. Yes if you use it as a wrapper as i describe in this post, and use Log4j in your end application.

    In our case, we have developped more than 15 modules each using JDK logging to not pollute client applications.

    We have several types of client applications: 5 of them are webapps. In our webapp, we redirect all JDK logging to Log4j.

    We have a Jetty in production using jms, redis, jdbc, ... and serving those 5 webapps. Each webapp thus have its own jdk log manager redirecting to the webapp's log4j config.

    ReplyDelete
  5. "A library should not rely on an external dependency..." that's exactly the problem apache commons was setup to solve. Unfortunately it turned out to be a bigger problem. Also remember using the java.util's logging auto forces all you clients to use the JDK 1.5+ platform

    ReplyDelete
  6. How did apache commons turn out to be a bigger problem? I've used with relatively little trouble. Thanks!

    ReplyDelete
  7. @anon, the same way the rest of them do. It adds dependencies which are not part of core Java. The primary flaw with java.util.logging was that it didn't use a jdbc approach to allow implementations to be loaded via a config of some kind.

    ReplyDelete
  8. The mains ideas I wanted to highlight in this article is that:

    1 - when you are a library developer, you should have in mind to reduce your transitive dependencies which are considered internal and which are not part of the features you provide.

    => using the JDK API can be a good way to have smaller dependencies, reduce impacts and configuration requirements. This is quite important if you work in mobile development in example.

    2 - using the JDK API does not force you and does not force the clients of the library to use the JDK logging system (logging.properties or others).

    => I hate the JDK logging configuration: so in the client applications, I use to redirect all the calls to log4j, which I configure accordingly in the client applications

    This way you can provide to the community a simple and lighter library with no constraints on the client side. And if the client want, a day, to debug your library, he has the possibility to redirect all logs to the logging system of his choice.

    ReplyDelete
  9. Hi,
    Thanks for htis Nice artilce just to add while discussing about HashMap its worth mentioning following questions which frequently asked in Java interviews now days like How HashMap works in Java or How get() method of HashMap works in JAVA very often. on concept point of view these questions are great and expose the candidate if doesn't know deep details.

    Javin
    FIX Protocol tutorial

    ReplyDelete
  10. Thanks for this article. I'm trying to understand the ins and outs of logging in Java(pretty complex) and this helps put some things in perspective.

    However, what happens to developers who like commons logging and would like to assume that all libraries use it? If they don't find your article (and wrapper code), how will the JDK logging that occurs in a library show up if they have adopted commons logging mapped to log4j for example? A separate set of log files? Could there be log file name collisions?

    Regards,

    -SB

    ReplyDelete
  11. Hi,

    The wrapper code is only when you NEED to see the logs of a library. This is not often... So if you are always in a project like me where some libraries such as Mycila, Ovea projects, Google Guice, ... are using JDK Logging plus others like Shiro, ActiveMQ, are using commons-logging and SLF4J, you will, at the end, use log4j.

    So the wrapper is simply there to catch the logs from the JDK logger and send them yo Log4j. There is no conflict.

    ReplyDelete
  12. hi,
    where will be the log files saved???

    ReplyDelete
  13. Do you know what is a wrapper, adapter ? Do you know what is log4j ? Do you know what is the JDK logging system ?
    Be sure to understand those: you'll see your question does not make sense after ;-)

    Logs are saved according to what you configured, as usual.

    ReplyDelete
  14. hi,
    i have tried to use your adapter, but i get always the INFO === No ContextualLogManager available ===, what could i solve this problem. i have done every thing as you have written

    ReplyDelete
  15. Did you double-check the important notice in the project page, concerning the location of the jar ?

    ReplyDelete
  16. JUL is not really designed to be a wrapper--even routing around it causes a performance hit: http://slf4j.org/legacy.html#jul-to-slf4j

    Also, JUL requires of my application something that Slf4j does not: I must install a LogManager before anything happens that I might want to log.

    I find LogBack's default log format MUCH superior to JUL's (which is fixed).

    These 3 issues make JUL entirely unacceptable to me. Slf4j will always be in my classpath anyway to unify commons-logging, slf4j, and log4j-bound components so I'm all for routing it to LogBack (preferred) or Log4j (acceptable).

    It really bothers me that JUL has defenders--I consider it a failed experiment.

    ReplyDelete
  17. This post is a mass of FUD and confusion:

    "You aim to have in your web application at then end all of these stupid wrappers because libraries depends on them."

    Actually the opposite is true. Wrappers allow you to use any logging impl you like.

    "So why the hell are people keep using libraries like SLF4J or commons-logging or even more !!!!"

    It is a best practice to code to a wrapper which allows the logging implementation to vary at runtime. Your argument for JUL seems to be one less jar?

    "You also write the same code when you want to log something."

    This is true for all wrappers.

    "But this is not the case anymore !!!"

    Cannot imagine recommending this code to anyone. A wrapper decouples you from the logging implementation. But your code couples the application to an implementation (log4j). Wacky, right?

    ReplyDelete
  18. Why do people avoid the JDK logger?

    SEVERE (highest value)
    WARNING
    INFO
    CONFIG
    FINE
    FINER
    FINEST (lowest value)

    That's why. Too many logging levels, with no real indication of when you should use one or the other. That, and the total lack of supports (it's missing a lot of features and they will never get implemented).

    slf4j is as close to a perfect API I've seen in the logging world. That's good enough for me.

    ReplyDelete