by Ceki Gülcü, November 14th, 2002, last updated October 29th, 2009, © All rights reserved
Given that log4j is such a low-level library, most organizations are hesitant to tie their code to log4j, especially considering the new logging API included in JDK 1.4. Before going forward, it is appropriate to mention that these two APIs are very similar. The classical usage pattern for log4j is:
import org.apache.log4j.Logger;
public class MyClass {
final static Logger logger = Logger.getLogger("some.name");
public void foo1() {
logger.debug("Hello world.");
}
public void foo2() {
logger.info("Another message.");
logger.error("Stop that!",
new Exception("The earth is getting warmer."));
}
}
As you are well aware by now, one of the important benefits of log4j is that it can be configured at run time using configuration scripts. You can have hundreds or thousands of log statement but only one or two lines of Java code to configure log4j. The usage pattern for the JDK 1.4 logging API is:
import java.util.logging.Logger;
public class MyClass {
final static Logger logger = Logger.getLogger("test");
public void foo1() {
logger.debug("Hello world.");
}
public void foo2() {
logger.info("Another message.");
logger.error("Stop that!",
new Exception("The earth is getting warmer."));
}
}
Although the log4j API is at least two years older than JDK 1.4, notice the extent to which the two APIs are similar. The JDK 1.4 logging API also supports configuration scripts. Being part of the JDK, some users reckon that the JSR47 API will supplant log4j some time in the near future. Surprisingly enough, it is not easy to write a complete logging API. Users come to realize they need the features present in log4j but absent in JDK 1.4 logging. Moreover, log4j runs under JDK 1.1 or later whereas JDK 1.4 logging requires, well, JDK 1.4. Most users can't afford to tie their code to JDK 1.4. But they need logging and they need it now. A common strategy for protecting against future changes and at the same time to benefit from existing log4j features is to wrap log4j with a custom logging API. Log4j actually has support to facilitate such wrappers.
Although not particularly difficult, it turns out that wrappers
are not trivial to write. I frequently receive email where a user
runs into a problem with their wrapper and requests help. More
often than not, these wrappers are of doubtful quality such that
the cost of inactive (or disabled) logging statements is
multiplied by a factor of 1'000 (one thousand) compared to direct
log4j usage. The most common error in wrapper classes is the
invocation of the Logger.getLogger method on each log
request. This is guaranteed to wreak havoc on your application's
performance. Really!!!
Of course, not all wrappers are of poor quality. For example, the commons-logging API is a prime example of a reasonable implementation. The commons-logging API will try to use different logging frameworks depending on their presence on the class path. See commons-logging project for more details. Obviously, even a good wrapper will carry a small overhead but that is not the point. The aspect where most users have difficulty is the initialization of the log4j API. Where should log4j.jar go? Where do I put the log4j.properties file? Can different web-applications have different log4j configurations? How do I initialize log4j in an application server? Although there is ample literature on the subject, much confusion remains.
The commons-logging API supporting multiple logging frameworks has its own "discovery process" which is based on the resources available to a particular classloader. In addition, the commons-logging API will create its own logger wrapper for each and every class loader in use within your application. The class loader based automatic "discovery process" is the principal weakness of the commons-logging API because it results in a substantial jump in complexity. The problem's severity is not due to users who can't RTFM or incompatible log4j versions. According to the java language, two classes loaded by different class loaders are totally incompatible even if they are bit-wise identical. If you opt for the commons-logging API, then the behavior of your system will depend on external circumstances which you as a developer cannot control. In general, all solutions based on class loading hacks are brittle and result in painful bugs. Moreover, these bugs can only be fixed by displacing jar files more or less at random. The real bug hides in the discovery process of commons-logging. It cannot be fixed without getting rid of the class loading hack behind the discovery process. If things were confusing before, they will be even more perplexing when commons-logging API enters widespread usage. For a more comprehensive discussion class loader problems involving JCL, please read the article "Taxonomy of class loader problems encountered when using Jakarta Commons Logging".
Since the primary goal of the commons-logging API is to discover and use the logging framework that is available at runtime, it can only cater for lowest common denominator of the different logging frameworks. As JDK 1.4 logging does not offer the same set of features as log4j, by using the common-logging API you would be missing those extra features, such as logging domains (a very useful feature planned for log4j version 1.3), Nested Diagnostic Contexts (NDC) and Mapped Diagnostic Contexts (MDC) which are essential features in server-type applications.
Unexpected interactions between log4j and a commons-logging wrapper API are also quite probable. The developers of the wrapper will suspect a log4j problem and conversely the log4j developers will suspect a wrapper problem. By increasing the number of components required for logging the probability of bugs increases while the difficulty of resolving them increases by a higher factor. My main argument against wrappers is the increased complexity of the resulting logging component. The justification for the existence of logging in the first place is to facilitate problem identification. As such, the logging component must be robust and simple to set up. The more complex the logging component gets, the less useful it becomes. Logging is rarely the main focus of an application. Experience shows that if setting up logging involves many steps or consumes too much time, software developers and users simply begin ignoring the logging component. Logging must be simple and robust to be useful.
There is mounting evidence to support my claims about increased complexity. Here are few examples:
Note that some of these bugs are reported by extremely competent developers.
Reading the above you might think that it is all theoretical mumbo-jumbo. After all, commons-logging is used in many libraries. Who is the author to challenge the wisdom of literally hundreds of developers who decided to adopt the commons-logging API, and apparently with success?
Interestingly enough, even if you decide not to depend on commons-logging you might be forced to depend on it indirectly through other libraries that make up your application. For example, this site, i.e. http://www.qos.ch was built using Tomcat and Struts both of which depend on commons-logging.
The dependence of struts on commons-logging is less troublesome because, normally one would place commons-logging.jar as well as struts.jar under the WEB-INF/lib/ directory. Since according to the Servlet API specification a servlet container should give precedence to libraries in WEB-INF/lib/, the dependency is constrained to within your application.
The case for the Tomcat 4.1.x series is quite different because the classloader hierarchy of Tomcat is much more complicated. For some reason, Tomcat ships with commons-logging-api.jar in common/lib/ and with commons-logging.jar in server/lib/. The jar files commons-logging.jar and commons-logging-api.jar differ in their support for log4j and avalon-logkit. The former supports JDK 1.4 logging, log4j and logkit while the latter only supports JDK 1.4 logging. I do not know the reasons behind this discrepancy. Other versions of Tomcat ship only one copy of commons-logging.jar.
Actually, I only became aware of Tomcat's deployment of commons-logging-api.jar and commons-logging.jar files once I was confronted with bug 17323.
Bug 17323 occurs when the users starts downloading a file in SSL
mode and decides to hit escape in the middle. This will cause a
java.net.SocketException to be thrown by the SSL
connector, effectively killing the SSL connector. After a while you
will run out of SSL connections so that Tomcat will stop serving
requests made through SSL. In other words, your web-site will come
to a screeching halt.
The identification of this problem will be greatly complicated
if you were using commons-logging and log4j in your web-application
because the java.net.SocketException cannot be
reported due to another bug in
org.apache.tomcat.util.log.CommonLogHandler inducing
you to think that the bug was caused by your logging setup.
There are a number of powerful forces working against you. First, your web-server dies a slow and almost imperceptible death because with the default Tomcat configuration you can count on 75 SSL connectors. Each of these will eventually die when some visitor cancels a file download. It will take days or weeks before the server runs out of connectors but eventually and invariably it will. Each time this happens, a seemingly perfect server that ran fine for days will just stop responding.
Your attempts to identify the problem will be severely impeded because Tomcat's log files will contain many (75 to be precise) stack traces similar to the following:
Feb 23, 2003 5:44:46 PM org.apache.tomcat.util.log.CommonLogHandler log
SEVERE: Caught exception executing
org.apache.tomcat.util.net.TcpWorkerThread@1e4eb5b, terminating thread
org.apache.commons.logging.LogConfigurationException:
org.apache.commons.logging.LogConfigurationException:
org.apache.commons.logging.LogConfigurationException: Class org.apache.\
commons.logging.impl.Log4JCategoryLog does not implement Log
at org.apache.commons.logging.impl.LogFactoryImpl.newInstance
(LogFactoryImpl.java:555)
at org.apache.commons.logging.impl.LogFactoryImpl.getInstance
(LogFactoryImpl.java:289)
at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:409)
at org.apache.tomcat.util.log.CommonLogHandler.log
(CommonLogHandler.java:97)
at org.apache.tomcat.util.log.Log.log(Log.java:198)
at org.apache.tomcat.util.log.Log.log(Log.java:192)
at org.apache.tomcat.util.net.PoolTcpEndpoint.log
(PoolTcpEndpoint.java:427)
at org.apache.tomcat.util.net.TcpWorkerThread.runIt
(PoolTcpEndpoint.java:510)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run
(ThreadPool.java:530)
at java.lang.Thread.run(Thread.java:536)
Caused by: org.apache.commons.logging.LogConfigurationException:
org.apache.commons.logging.LogConfigurationException: Class org.apache.comm
ons.logging.impl.Log4JCategoryLog does not implement Log
at org.apache.commons.logging.impl.LogFactoryImpl.getLogConstructor
(LogFactoryImpl.java:420)
at org.apache.commons.logging.impl.LogFactoryImpl.newInstance
(LogFactoryImpl.java:548)
... 9 more
Caused by: org.apache.commons.logging.LogConfigurationException: Class
org.apache.commons.logging.impl.Log4JCategoryLog does not implement Log
at org.apache.commons.logging.impl.LogFactoryImpl.getLogConstructor
(LogFactoryImpl.java:416)
... 10 more
These stack traces are likely to convince you that the problem lies with logging rather than the SSL connector. Under these circumstances, it really takes a lot of determination to identify the problem. The bug is impossible to reproduce and the stack traces throw you at the wrong direction. At this juncture, you might be tempted to ditch log4j or commons-logging or even Tomcat.
After much groping in the dark I was lucky enough to identify and report the bug. The Tomcat developers have recently reported to have fixed the bug. However, who knows how many bugs are still lurking in the code and whose identification is made excruciatingly difficult by the lack of correct stack traces.
Logging was supposed to help identify problems, not obscure them. Hopefully the Tomcat developers will heed the message.
Several users have reported problems when using log4j in conjunction with Tomcat. The problem was initially reported on 2004-01-23 as tomcat bug number 26372. At 11:54, just 4 minutes after bug number 26372 was filed, Remy Maucherat summarily dismissed it, saying:
This is the old issue of log4j trying to use the previous classloader (reloading will create a new classloader to load class definitions; see bug 3888). Maybe it would be good to leave this bug open so that people can complain using it, rather than file duplicates. However, I'd like everyone to know that the "bug" will never be fixed. You can probably fix the problem by putting log4j JARs (and the necessary commons-logging wrapper classes) inside the webapp repository.
Following countless bug hunting sessions by frustrated developers around the world, and after about 9 months of ping and pong, it finally occurred to someone, namely Andy McBride, that the problem might lie with commons-logging holding references to classloader instances. This was acknowledged by Craig McClanahan. However, the java.lang.ThreadDeath bug remains unsolved to this day (2004-08-11). Since the nature of the bug, let alone its solution, continute to elude the tomcat developers, it may be too early to convict commons-logging.
When a reliable solution remains elusive and only a shaky one is available, then one is often better served with no solution at all. There is a point to the ThreadDeath story. In larger software systems, it can take several years for a bug to be identified correctly. During that lengthy period your users will be frustrated and the good reputation of your software will suffer. Thus, from the beginning of development to its end, a good software engineer will actively eschew shaky hacks, even at the cost of useful features.
Several other developers have complained about the difficulties involved in using commons-logging. Here is a short list.
Commons-logging promises to bridge to different logging APIs
such as log4j, Avalon logkit and java.util.logging
API. However, it's dynamic discovery mechanism is the source of
painful bugs. In practice, JCL can only safely bridge the
java.util.logging API.