Friday, September 4, 2009

Logging: should I wrap?

Once upon a time, there was a de facto logging standard, log4j. Then Sun decided to confuse matters by introducing another -- and many say inferior -- logging API in JDK 1.4. Some people responded with Jakarta Commons Logging (JCL), a wrapper that abstracts away these two APIs. Some other people decided that JCL was awful, and wrote SLF4J, a wrapper that abstracts away the first two APIs and JCL. There are also other logging implementations like Logback and x4juli, but fortunately these natively implement the existing APIs so they don't multiply the confusion.

If you start work on an existing project, I suppose you'd use whatever logging API is already in use. If on the other hand you are lucky enough to start a brand new project, you have to choose from a number of logging APIs:
  • log4j
  • JDK Logging
  • JCL
  • SLF4J
The conventional wisdom is that if you are writing a component or library, you'd likely choose one of the wrapper APIs (JCL or SLF4J) since you won't have control over what logging implementation the actual app will use. On the other hand, the conventional wisdom continues, if you are working on a standalone application you might as well code directly to the native APIs since you can pick the logging engine and are unlikely to switch. Even SLF4J's docs say that you needn't bother with SLF4J for standalone applications.

I have joined projects that build J2EE applications almost from scratch, so we got to pick the logging API. My initial inclination was the direct approach: we'd code directly to log4j. After all, why add an unnecessary abstraction? In one project, we ended up using SLF4J, even though we had no intention of switching logging engines. Why? Well, it turns out that SLF4J has a useful feature that log4j does not: parameterized logging. Ordinary logging messages incur the overhead of building the log message even if the message will not be logged at the current log level:

logger.debug("Value of obj#" + i + " = " + obj.toString());

All that work will be wasted if you are logging at the INFO level. The performance penalty could be significant if obj.toString() is particularly heavy. You could wrap that line in an "if (logger.isDebugEnabled()) {...}" block, but that adds clutter. SLF4J lets you defer evaluation of any String conversions until the line is actually written:

logger.debug("Value of obj#{} = {}", i, obj);

Does this minor convenience justify throwing in yet another 3rd party library? We did not need to answer that question. In a substantial app, there is no extra overhead. Quite likely, as in our case, the third party libraries you use will require JCL (e.g., Spring) and SLF4J (e.g., Hibernate) anyway. It's up to you to choose the API for your own logging. For us, SLF4J came along for the ride, gave us the parameterized expressions and still exposed powerful features like Mapped Diagnostic Context (MDC). Where is the downside?

In another project, we coded straight to the log4j API. This project was coded almost entirely in Groovy. In Groovy, we get lazy evaluation for free, so SLF4J offered no API benefits. The Groovy logging code below lazily evaluates its parameters regardless of logging implementation, and more concisely than SLF4J:

logger.debug "Value of obj#${i} = ${obj}"

4 comments:

  1. I don't prefer JCL because it doesn't allow Log4J's MDC and NDC to filter through. I've used SLF4J just a bit and I really like it. Here's a popular blog entry I wrote on the topic a couple years ago:

    http://bsnyderblog.blogspot.com/2007/08/my-soapbox-for-slf4j.html

    ReplyDelete
  2. Lately I have been experimenting with logging only for error and INFO. For all other purposes I m sticking to in memory state and circular fifos. Externally state can be queried using JMX.

    ReplyDelete
  3. We are using Weblogic 9.2 and Log4j for logging the application logs
    Our Application is used by Multiple testers.
    All the Application Logs go to common Log file "APP.log"
    So each tester have to scroll down through the file to find his/her each piece of log.


    For Weblogic 9.2 Server We have file called "config.xml" , This File gets updated when anything is changed or updated from the Weblogic Console.

    In this "config.xml" File , We have a Server setting like below :
    -Dlog4j.configuration=file:/srvrs/dev/apacheLog4jCfg.xml

    This Setting is referring to File called "apacheLog4jCfg.xml" Which means that Weblogic Server is using apache Log4j to do the logging.

    In "apacheLog4jCfg.xml" File We have the setting like below :

    Appender Name is APPLOGFILE and class is org.apache.log4j.RollingFileAppender
    param name is File and value is APP.log

    This Setting will log all the application logs to the File "APP.log"
    i.e All the testers will hit the application and all the logs will get stored in the File "APP.log"

    I have two questions below :
    Q1 : So Using log4j , Is it possible that for each Tester testing the application , a separate log file should be created, So that he/she can see their own set of logs ?

    Q2 : Is it possible to instruct the Weblogic Container or do Server side setting programmatically to use log4j at one point of time for logging to samelog file for all users OR to to instruct the Weblogic Container to use to sl4j , if we want to log to different log files for different users ?

    ReplyDelete
    Replies
    1. Anonymous,

      You are essentially looking for
      1. logging by "Session" i.e a log file per user session.
      2. log file per user (across all his sessions)

      AFAIK - this can be done only in a custom way, there is no out-of-box config or solution to this.

      Delete