I would like to thank Jacob Kjome for reviewing early drafts of this document. His comments helped to clarify several important points. Jake also keeps reminding us on the log4j-dev mailing list that the child-parent delegation model is not the only model out there and that parent-first delegation model is alive and well. Niclas Hedhman and Yoav Shapira have also made very valuable suggestions. Scott Deboy, Paul Delano, Robert Burrell Donkin, Frank-Olaf Lohmann, Dugald Morrow, Nain Hwu, Toni Price, Peter Royal, Richard Lawrence and Henning Schmiedehausen have kindly pointed out errors of typographical and grammatical nature.
I've tried to make this document error-free; however I will
gladly offer a copy of "The
complete log4j manual" to the initial reporter of any error,
be it technical, typographical or otherwise. You are highly
encouraged to send your comments or critical reviews to c e
k i @ q o s . c h
.
If you are not interested in JCL's bugs but are looking for a quick solution for a current problem, you can skip to the section entitled Short term solutions.
This article was tested with Jakarta Commons Logging version 1.0.4. Several proposals were put forth to correct the problems in JCL's discovery code. However, there hasn't been any tangible progress so far.
This document attempts to systematically categorize the types of problems encountered when using Jakarta Commons Logging, hereafter abbreviated as JCL. After reading Richard Sitze's analysis about class loader problems with the JCL discovery mechanism, it occurred to me that while most people agreed JCL's dynamic discovery mechanism was problematic, it was not always easy to get a grasp around them. Hopefully, the sample code accompanying this document will allow the reader to easily reproduce at least the basic bugs. As Donald Knuth once noted, we all learn best the things that we have discovered ourselves. I hope that readily reproducing JCL's error conditions will pave the way for a better understanding of the problem domain by a wide public.
For the convenience of the reader, all source code as well as class and jar files that are needed to run the examples in this document are bundled within a single file named cl-problems.zip.
If you have the time, I suggest that you take the afternoon to go through the examples hands on. It's impossible to get a feeling for this topic just by reading the article.
It is assumed that the reader has a basic understanding of how Java class loaders work. To refresh your memory, I recommend reading the following articles.
Class loading problems encountered when using JCL fall into three main categories:
java.lang.NoClassDefFoundError
thrown when a class
is inaccessible from a parent class loader even if the said
class is available to a child class loaderAt least on a superficial level, Type-I problems are relatively easy to understand whereas Type-II problems are a bit harder to grasp at first glance. Consequently, we will start by illustrating problems of Type-I. Given their different nature, Type-III problems will be discussed only briefly towards the end of this document.
As you probably know, a class loader usually has a reference
to its parent. It follows that class loaders can be arranged into
trees of class loaders. In order to retrieve a resource, a class
loader will normally delegate to its parent first. The
javadoc documentation of the Classloader
class
states:
The ClassLoader
class uses a
delegation model to search for classes and resources. Each
instance of ClassLoader
has an associated parent
class loader. When called upon to find a class or resource, a
ClassLoader
instance will delegate the search for
the class or resource to its parent class loader before
attempting to find the class or resource itself. The virtual
machine's built-in class loader, called the bootstrap class
loader, does not itself have a parent but may serve as the parent
of a ClassLoader
instance.
Thus, parent-first delegation is the default and recommended delegation model in Java.
However, under certain circumstances, a child class loader may prefer to first attempt to load resources on its own, and only later to delegate to its parent. We refer to this kind of class loaders as following the child-first delegation model. The Java Servlet Specification Version 2.4 states the following:
SRV.9.7.2 Web Application Classloader
The classloader that a container uses to load a servlet in a
WAR must allow the developer to load any resources contained in
library JARs within the WAR following normal J2SE semantics
using getResource
. It must not allow the WAR to
override J2SE or Java servlet API classes. It is further
recommended that the loader not allow servlets in the WAR
access to the web container's implementation classes. It
is recommended also that the application class loader be
implemented so that classes and resources packaged within the
WAR are loaded in preference to classes and resources residing
in container-wide library JARs.
Note that the Servlet Specification only recommends child-first delegation order. In practice, not all Servlet Containers implement the child-first delegation model. Both delegation models are fairly common in practice.
In order to write small test cases reproducing class loader problems, we need one class loader implementation for the parent-first delegation model and another implementation for the child-first model. Fortunately, a class loader for the parent-first delegation model is readily available. Not only does java.net.URLClassLoader implement the parent-first model, it is also very convenient to use.
As far as I know, there is no class loader implementing the child-first model that ships with the JDK. However, it does not take much to write our own.
/** * An almost trivial no fuss implementation of a class loader * following the child-first delegation model. * * @author Ceki Gülcü */ public class ChildFirstClassLoader extends URLClassLoader { public ChildFirstClassLoader(URL[] urls) { super(urls); } public ChildFirstClassLoader(URL[] urls, ClassLoader parent) { super(urls, parent); } public void addURL(URL url) { super.addURL(url); } public Class loadClass(String name) throws ClassNotFoundException { return loadClass(name, false); } /** * We override the parent-first behavior established by * java.lang.Classloader. * * The implementation is surprisingly straightforward. */ protected Class loadClass(String name, boolean resolve) throws ClassNotFoundException { // First, check if the class has already been loaded Class c = findLoadedClass(name); // if not loaded, search the local (child) resources if (c == null) { try { c = findClass(name); } catch(ClassNotFoundException cnfe) { // ignore } } // if we could not find it, delegate to parent // Note that we don't attempt to catch any ClassNotFoundException if (c == null) { if (getParent() != null) { c = getParent().loadClass(name); } else { c = getSystemClassLoader().loadClass(name); } } if (resolve) { resolveClass(c); } return c; } }
In a nutshell, ChildFirstClassLoader
extends java.net.URLClassLoader
and overrides its
loadClass()
method so that parent delegation occurs
only after an unsuccessful attempt to load a class
locally.
Now that we have the class loader implementations, we also need
one or two classes to load and play with. We will play with various
versions of the Box
interface shown next.
package box; /* * Box is a small two method interface. We don't really care about * what implementations of the Box interface do, as long as they * implement its two methods. * * @author Ceki Gülcü */ public interface Box { /** * Returns the version number of the implementing class. */ public int get(); /** * Perform some operation. We don't really care what it is. */ public void doOp(); }
Here is a quasi-trivial implementation of Box
.
package box; /** * A no brainer implementation of Box returning a number. This * number is set at compilation time by Ant. * * @author Ceki Gülcü */ public class BoxImpl implements Box { /** * Create an instance of BoxImpl and print it. */ static public void main(String[] args) { Box box = new BoxImpl(); System.out.println("BoxImpl version is "+box.get()); } /** * The appropriate Ant task replaces @V@ with an integer constant. */ public int get() { return @V@; } /** * Print this instance as a string. */ public void doOp() { System.out.println(this); } /** * Returns this instance's string representation. */ public String toString() { return "BoxImpl("+get()+")"; } }
In the accompanying distribution to this document,
you will find 3 jar files. The file boxAPI.jar includes
Box.class and nothing else. The file box0.jar
includes a version of the class BoxImpl
which returns
zero (0) in its get()
method. The file
box1.jar includes a version of the class
BoxImpl
which returns one (1) in its get()
method.
Executing the command
java -cp boxAPI.jar;box0.jar box.BoxImpl
yields
Box version is 0
Whereas executing the command
java -cp boxAPI.jar;box1.jar box.BoxImpl
yields
Box version is 1
This shows that the jar files box0.jar and box1.jar contain implementations marked with different version numbers.
The java applications ChildFirstTest
and ParentFirstTest
included in the distribution demonstrate that
ChildFirstClassLoader
and URLClassLoader
respectively implement the child-first and parent-first delegation
mechanisms.
They can be run as follows:
java -cp classes;boxAPI.jar;box0.jar ch.qos.test.ChildFirstTest
and respectively as
java -cp classes;boxAPI.jar;box0.jar ch.qos.test.ParentFirstTest
In parent-first class loader trees JCL suffers from problems of Type-I. To understand the causes, several facts must be carefully reviewed.
JCL relies on dynamic discovery to determine the user's preferred
logging API. In theory, log4j, java.util.logging
and
Avalon logkit are supported. In order to locate classes and
resources, JCL's discovery mechanism relies exclusively on
the thread context class loader which is by definition the class
loader returned by the getContextClassLoader()
method for the current thread. As long as the thread context class
loader (TCCL) is not explicitly defined, it defaults to the system
class loader, that is the class loader used to load the application.
In the following three examples, the system class loader will
have access to boxAPI.jar, commons-logging.jar and
the classes/ directory. An instance of
URLClassLoader
(parent-first delegation), will have the
system class loader as its parent. It will also have access to
box1.jar, commons-logging.jar and
log4j.jar.
This first example, ParentFirstTestJCL0, will not explicitly set the TCCL. Thus, the TCCL will default to the system class loader. Please note that this example does not illustrate a bug in JCL but rather serves as a warm up for the rest of the examples.
public class ParentFirstTestJCL0 { public static void main(String[] args) throws Exception { URLClassLoader childClassLoader = new URLClassLoader( new URL[] { new URL("file:box1.jar"), new URL("file:lib/commons-logging.jar"), new URL("file:lib/log4j.jar") }); Log log = LogFactory.getLog("logger.name.not.important.here"); log.info("a message"); Class boxClass = childClassLoader.loadClass("box.BoxImplWithJCL"); Box box = (Box) boxClass.newInstance(); System.out.println(box); box.doOp(); } }
The ParentFirstTestJCL0
application creates a child
class loader of type URLClassLoader
and adds
box1.jar, commons-logging.jar and
log4j.jar to it. In the next two lines, a JCL
Log
instance is retrieved by LogFactory
and used to log a message. The child class loader is then used to
create an instance of box.BoxImplWithJCL
. We
then call the doOp
method of the newly created
BoxImplWithJCL
instance. The doOp()
method
in BoxImplWithJCL
invokes the
LogFactory.getLog
method to retrieve a Log
instance and then uses it to log a simple message.
The next diagram illustrates this configuration more graphically.
Running the command:
java -cp boxAPI.jar;classes;lib/commons-logging.jar ch.qos.test.ParentFirstTestJCL0
yields
Feb 6, 2005 3:44:45 PM ch.qos.test.ParentFirstTestJCL0 main INFO: a message Feb 6, 2005 3:44:45 PM box.BoxImplWithJCL doOp INFO: hello
Wait a minute, that is output from java.util.logging, not log4j! How did that happen?
Although we could load box.BoxImplWithJCL
using the
child class loader (only it had access to box1.jar), JCL
ignored log4j.jar in the child class loader because the
thread context class loader was not set. JCL then discovered
java.util.logging
which provides a default
configuration directing messages of level INFO and above to the
console.
In the next example, we will explicitly set the thread context class loader (TCCL) and subsequently run into a whole new set of problems.
The ParentFirstTestJCL1
application is similar to ParentFirstTestJCL0
except
that it explicitly sets the child class loader as the TCCL. It then
loads a new instance of BoxImplWithJCL
and attempts to
invoke the doOp
method on that instance.
package ch.qos; public class ParentFirstTestJCL1 { public static void main(String[] args) throws Exception { URLClassLoader childClassLoader = new URLClassLoader(new URL[] { new URL("file:box1.jar"), new URL("file:lib/commons-logging.jar"), new URL("file:lib/log4j.jar")}); Thread.currentThread().setContextClassLoader(childClassLoader); Class boxClass = childClassLoader.loadClass("box.BoxImplWithJCL"); Box box = (Box) boxClass.newInstance(); box.doOp(); } }
The class loader configuration for Example-2 is illustrated in the figure below.
Running the following command
java -cp boxAPI.jar;classes;lib/commons-logging.jar ch.qos.test.ParentFirstTestJCL1
yields:
Exception in thread "main" org.apache.commons.logging.LogConfigurationException: \ org.apache.commons.logging.LogConfigurationException: No suitable Log constructor [Ljava.lang.Class;@12b66 for org.apache.commons.logging.impl.Log4JLogger Caused by java.lang.NoClassDefFoundError: org/apache/log4j/Category) Caused by org .apache.commons.logging.LogConfigurationException: No suitable Log constructor [Ljava.lang.Class;@12b6651 for org.apache.commons.logging.impl.Log4JLogger (Caused by java.lang.NoClassDefFoundError: org/apache/log4j/Category)) at org.apache.commons.logging.impl.LogFactoryImpl.newInstance(LogFactoryImpl.java:543) at org.apache.commons.logging.impl.LogFactoryImpl.getInstance(LogFactoryImpl.java:235) at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:370) at box.BoxImplWithJCL.doOp(BoxImplWithJCL.java:23) at ch.qos.test.ParentFirstTestJCL1.main(ParentFirstTestJCL1.java:44) Caused by: org.apache.commons.logging.LogConfigurationException: No suitable Log constructor [Ljava.lang.Class;@12b6651 for org.apache.commons.logging.impl.Log4J Logger (Caused by java.lang.NoClassDefFoundError: org/apache/log4j/Category) at org.apache.commons.logging.impl.LogFactoryImpl.getLogConstructor(LogFactoryImpl.java:413) at org.apache.commons.logging.impl.LogFactoryImpl.newInstance(LogFactoryImpl.java:529) ... 4 more Caused by: java.lang.NoClassDefFoundError: org/apache/log4j/Category at java.lang.Class.getDeclaredConstructors0(Native Method) at java.lang.Class.privateGetDeclaredConstructors(Class.java:1590) at java.lang.Class.getConstructor0(Class.java:1762) at java.lang.Class.getConstructor(Class.java:1002) at org.apache.commons.logging.impl.LogFactoryImpl.getLogConstructor(LogFactoryImpl.java:410) ... 5 more
What went wrong?
The LogConfigurationException
is thrown when we
attempt to log from the doOp()
method in box.BoxImplWithJCL
. The
BoxImplWithJCL
class is loaded and instantiated by the
child class loader. The child class loader delegates the loading of
the LogFactory
class to its parent. In order to return
a Log instance, at some point LogFactory invokes its
getLogConstructor()
method. The
LogConfigurationException
is thrown from within this
method.
On line 368 of LogFactoryImpl.java,
getLogConstructor()
invokes
getLogClassName()
. Given that the classes
org.apache.log4j.Logger
and
org.apache.commons.logging.impl.Log4JLogger
are visible
through the TCCL (defined to be the child class loader), the
getLogClassName()
method returns the string value
"org.apache.commons.logging.impl.Log4JLogger". On lines 373 through
398, the Log4jLogger
class is loaded into memory by the
parent class loader. The TCCL, i.e. the child class loader in this
example, delegates to its parent, the system class loader, which is
able to find JCL's Log4jLogger
class. This copy of
Log4jLogger
is compared against a copy of the
org.apache.commons.logging.Log
class which was also
loaded by the same class loader. The comparison succeeds and we
proceed to the next step.
JCL loads logging API implementation classes using the TCCL but hands down the work of obtaining the constructor method to the current class loader. This discrepancy is at the heart of JCL's class loader problems of Type-I.
On line 410, the Class.getConstructor()
method is
invoked on the Log4jLogger
class -- loaded by the
parent class loader. This in turn triggers the loading of log4j's
Logger
class. This is done using the class loader that
loaded the Log4jLogger
class, i.e. the parent class
loader, which cannot see log4j.jar
, hence the root
java.lang.NoClassDefFoundError
exception about
org.apache.log4j.Category
being undefined. In other
words, JCL loads logging API implementation classes using the TCCL
but hands down the work of obtaining the constructor method for the
implementation class to the current class loader. This discrepancy
is at the heart of JCL's class loader problems of Type-I.
Log4jLogger
from
commons-logging.jarThe file commons-logging-api.jar which ships with the
JCL distribution is identical to commons-logging.jar except
that the former does not include the
org.apache.commons.logging.impl.Log4JLogger
and
org.apache.commons.logging.impl.AvalonLogger
classes.
Interestingly enough running ParentFirstTestJCL1
with commons-logging-api.jar on the class path gives better
results. The class loader configuration for Example-2B is illustrated
in the figure below.
Running ParentFirstTestJCL1
with
commons-logging-api.jar on the class path as:
java -cp boxAPI.jar;classes;lib/commons-logging-api.jar ch.qos.test.ParentFirstTestJCL1
will load log4j classes without errors. Indeed, the
Log4JLogger
class will be loaded by the child class
loader instead of the parent which cannot see
Log4JLogger
. The child class loader will also be able
to load log4j classes.
Unfortunately, this approach has the obvious inconvenience of preventing the use of of log4j (or any other API residing outside the JDK) by classes loaded by the parent class loader, even if log4j classes are visible to the parent class loader.
Placing commons-logging-api.jar in the parent class loader is safe but precludes the use of log4j by classes directly loaded by the parent class loader. We will come back to this point when discussing child-first class loader trees. As shown in Example-2, placing commons-logging.jar in the parent class loader is unsafe when log4j classes are visible to a child class loader, also defined to be the TCCL.
In simple English, JCL's discovery mechanism can safely bridge
only for java.util.logging
, other logging APIs residing
outside the JDK cannot be discovered in a safe manner in most
configurations.
The ParentFirstTestJCL2
application is very similar to ParentFirstTestJCL1
. It
illustrates that logging through JCL will fail as soon as the thread
context class loader is set to the child class loader.
package ch.qos;
public static void main(String[] args) throws Exception {
URLClassLoader childClassLoader =
new URLClassLoader(
new URL[] {
new URL("file:box1.jar"),
new URL("file:lib/commons-logging.jar"),
new URL("file:lib/log4j.jar")
});
Thread.currentThread().setContextClassLoader(childClassLoader);
// this will throw a NoClassDefFoundError
exception
Log log = LogFactory.getLog("logger.name.not.important.here");
}
Running
java -cp boxAPI.jar;classes;lib/commons-logging.jar ch.qos.test.ParentFirstTestJCL2
will yield the same error message as in the previous example.
In child-first class loader trees, JCL suffers from problems of both Type-I and Type-II. We will start this section with an example reproducing a Type-II problem.
The next example, ChildFirstTestJCL0,
demonstrates that when both a parent and child class loader have
direct access to commons-logging.jar and the TCCL is set to
point to the child class loader, the first call to JCL's
LogFactory.getLog()
method from a class directly loaded
by the parent class loader will throw an exception.
package ch.qos.test; import org.apache.commons.logging.Log; import org.apache.commons.logging.LogFactory; import ch.qos.ChildFirstClassLoader; public class ChildFirstTestJCL0 { public static void main(String[] args) throws Exception { ChildFirstClassLoader child = new ChildFirstClassLoader( new URL[] { new URL("file:lib/commons-logging.jar") }); Thread.currentThread().setContextClassLoader(child); // JCL will throw an exception as soon as LogFactory is called after the // TCCL is set to a child class loader, and both the parent and child // have direct access to commons-logging.jar Log log = LogFactory.getLog("logger.name.not.important.here"); } }
The class loader configuration for Example-4 is illustrated in the figure below.
Running application ChildFirstTestJCL0 with the following command line
java -cp classes;lib/commons-logging.jar ch.qos.test.ChildFirstTestJCL0
will result in the following exception
Exception in thread "main" org.apache.commons.logging.LogConfigurationException: \ org.apache.commons.logging.LogConfigurationException: \ org.apache.commons.logging.LogConfigurationException: Invalid class loader hierarchy. \ You have more than one version of 'org.apache.commons.logging.Log' visible, which is not allowed. (Caused by org.apache.commons.logging.LogConfigurationException: Invalid class loader hierarchy. You have more than one version of 'org.apache.commons.logging.Log' visible, which is not allowed.) (Caused by org.apache.commons.logging.LogConfigurationException: \ org.apache.commons.logging.LogConfigurationException: Invalidclass loader hierarchy. \ You have more than one version of 'org.apache.commons.logging.Log' visible, which is not allowed. (Caused by org.apache.commons.logging.LogConfigurationException: Invalid class loader hierarchy. \ You have more than one version of 'org.apache.commons.logging.Log' visible, which is not allowed.)) at org.apache.commons.logging.impl.LogFactoryImpl.newInstance(LogFactoryImpl.java:543) at org.apache.commons.logging.impl.LogFactoryImpl.getInstance(LogFactoryImpl.java:235) at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:370) at ch.qos.test.ChildFirstTestJCL0.main(ChildFirstTestJCL0.java:43) Caused by: org.apache.commons.logging.LogConfigurationException: \ org.apache.commons.logging.LogConfigurationException: Invalid class loader hierarchy. \ You have more than one version of 'org.apache.commons.logging.Log' visible, which is not allowed. (Caused by org.apache.commons.logging.LogConfigurationException: Invalid class loader hierarchy. \ You have more than one version of 'org.apache.commons.logging.Log' visible, which is not allowed.) at org.apache.commons.logging.impl.LogFactoryImpl.getLogConstructor(LogFactoryImpl.java:397) at org.apache.commons.logging.impl.LogFactoryImpl.newInstance(LogFactoryImpl.java:529) ... 3 more Caused by: org.apache.commons.logging.LogConfigurationException: Invalid class loader hierarchy. \ You have more than one version of 'org.apache.commons.logging.Log' visible, which is not allowed. at org.apache.commons.logging.impl.LogFactoryImpl.getLogConstructor(LogFactoryImpl.java:385) ... 4 more
The exception is thrown because the Log
implementation loaded by the TCCL, i.e. the child class loader, is
not the same as the Log
interface in use within
LogFactory
(loaded by the parent class
loader). According to Section
4.3.2 of the Java Language Specification, two classes loaded by
different class loaders are considered to be distinct and hence
incompatible.
In the previous example, LogFactory
and
Log
classes were loaded by the parent loader while its
implementation was loaded by the TCCL. Example-4B demonstrates that
if the TCCL follows child-first delegation, then in case the
LogFactory
and Log
classes are loaded by
the TCCL, the Log
implementation will be compatible
since it will be loaded by the same class loader.
package ch.qos.test; import box.Box; import ch.qos.ChildFirstClassLoader; import java.net.URL; /** * Usage: * * java -cp classes;lib/commons-logging.jar ch.qos.test.ChildFirstTestJCL1 * * @author Ceki Gülcü */ public class ChildFirstTestJCL1 { public static void main(String[] args) throws Exception { ChildFirstClassLoader child = new ChildFirstClassLoader( new URL[] { new URL("file:lib/commons-logging.jar"), new URL("file:box1.jar")}); Thread.currentThread().setContextClassLoader(child); Class boxClass = child.loadClass("box.BoxImplWithJCL"); Box box = (Box) boxClass.newInstance(); box.doOp(); } }
Running
java -cp boxAPI.jar;classes;lib/commons-logging.jar ch.qos.test.ChildFirstTestJCL1
will output a log message using java.util.logging.
Previously in the fourth example, we have seen that having a copy
of commons-logging.jar in both the parent and child class
loaders will cause problems as soon as a class loaded by the parent
attempts to use JCL. In this fifth example, called ChildFirstTestJCL2,
we will remove commons-logging.jar from the child class
loader and hand it a copy of log4j.jar instead. It
demonstrates that when the parent class loader can see
commons-logging.jar and the child class loader (also set to
be the TCCL) can see log4j.jar, then as in the second and
third examples, JCL will throw a
LogConfigurationException
because it will not be able
to find the log4j classes.
package ch.qos.test; import java.net.URL; import box.Box; import ch.qos.ChildFirstClassLoader; /** * Usage: * * java -cp classes;boxAPI.jar;lib/commons-logging.jar ch.qos.test.ChildFirstTestJCL1 * * @author Ceki Gülcü */ public class ChildFirstTestJCL2 { public static void main(String[] args) throws Exception { ChildFirstClassLoader child = new ChildFirstClassLoader(new URL[] { new URL("file:box1.jar"), new URL("file:lib/log4j.jar") }); Thread.currentThread().setContextClassLoader(child); Class boxClass = child.loadClass("box.BoxImplWithJCL"); Box box = (Box) boxClass.newInstance(); box.doOp(); } }
The class loader configuration for Example-5 is illustrated in the figure below.
Running the command:
java -cp classes;boxAPI.jar;lib/commons-logging.jar ch.qos.test.ChildFirstTestJCL2
will cause the following exception to be thrown.
Exception in thread "main" org.apache.commons.logging.LogConfigurationException: \ org.apache.commons.logging.LogConfigurationException: \ No suitable Log constructor [Ljava.lang.Class;@4a5ab2 for org.apache.commons.logging.impl.Log4JLogger\ (Caused by java.lang.NoClassDefFoundError: org/apache/log4j/Category) (Caused by org.apache.commons.logging.LogConfigurationException: \ No suitable Log constructor [Ljava.lang.Class;@4a5ab2 for org.apache.commons.logging.impl.Log4JLogger (Caused by java.lang.NoClassDefFoundError: org/apache/log4j/Category)) at org.apache.commons.logging.impl.LogFactoryImpl.newInstance(LogFactoryImpl.java:543) at org.apache.commons.logging.impl.LogFactoryImpl.getInstance(LogFactoryImpl.java:235) at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:370) at box.BoxImplWithJCL.doOp(BoxImplWithJCL.java:23) at ch.qos.test.ChildFirstTestJCL2.main(ChildFirstTestJCL1.java:42) Caused by: org.apache.commons.logging.LogConfigurationException: \ No suitable Log constructor [Ljava.lang.Class;@4a5ab2 for org.apache.commons.logging.impl.Log4JLogger (Caused by java.lang.NoClassDefFoundError: org/apache/log4j/Category) at org.apache.commons.logging.impl.LogFactoryImpl.getLogConstructor(LogFactoryImpl.java:413) at org.apache.commons.logging.impl.LogFactoryImpl.newInstance(LogFactoryImpl.java:529) ... 4 more Caused by: java.lang.NoClassDefFoundError: org/apache/log4j/Category at java.lang.Class.getDeclaredConstructors0(Native Method) at java.lang.Class.privateGetDeclaredConstructors(Class.java:1590) at java.lang.Class.getConstructor0(Class.java:1762) at java.lang.Class.getConstructor(Class.java:1002) at org.apache.commons.logging.impl.LogFactoryImpl.getLogConstructor(LogFactoryImpl.java:410) ... 5 more
The causes for this exception are very similar to those discussed in the second example.
The ChildFirstTestJCL3 application is very similar to the previous example. It illustrates how logging by any class loaded by the parent class loader using JCL will fail as soon as the thread context class loader is set to the child class loader.
Suppose you are using Tomcat and wanted to use log4j in your web-application. In Tomcat, each web-application has its own class loader following the child-first delegation model. Suppose you add log4j.jar in your web-application's war file and add commons-logging.api in Tomcat's common/lib/ directory.. Well, in that case, you'd be reenacting the set up described in Example-5 and Example-6 and you'd be getting the same exceptions.
For the sceptical about the fidelity of this simulation, the distribution accompanying this document contains a small but complete web-application called "Hello" which can reproduce the problem in Tomcat.
In order to track the various logging implementations and their wrappers, JCL internally manages a hash table keyed by class loader. This causes problems of Type-III. Indeed, by holding strong references to class loaders, JCL prevents application containers from garbage collecting recycled web-applications. This limitation will be addressed in JCL version 1.0.5 by replacing the regular hash table with a WeakHashTable.
Until recently JCL was the only solution that provided an abstraction of various logging APIs. With the benefit of hindsight, the log4j project has developed an alternative solution called "Simple Logging Facade for Java" or SLF4J in short.
SLF4J supports multiple implementations, namely, NOP, Simple, log4j, JDK 1.4 logging and logback. SLF4J distributions ship with four jar files slf4j-nop.jar, slf4j-simple.jar, slf4j-log4j12.jarand slf4j-jdk14.jar. Each of these jar files is hardwired at compile time to use just one implementation, that is NOP, Simple, log4j12 and JDK 1.4 logging, respectively. Logback distributions ship with logback-classic.jar which implements the SLF4J API natively.
Unless the slf4j-xxx.jar or logback-classic.jar file is corrupt, static linking can never cause bugs of Type-I, Type-II or Type-III for the simple reason that all API bindings are done at compile time with all the required files bundled in the slf4j-xxx.jar or logback-classic.jar file.
You can verify this for yourself with the help of
BoxImplWithSLF4J
and related test cases found in the
distribution. In a nutshell, SLF4J will never behave unexpectedly or
crash your application.
Given the severity of the problems with JCL, we recommend that you consider switching to SLF4J which provides better functionality with none of the bugs. In the short term however, you can substantially alleviate some of the pain of using JCL in conjunction with log4j, if you exactly adhere to the following scenario.
Make sure that you are using JCL version 1.0.4 or later. Earlier versions of JCL pose problems beyond those discussed in this document.
org.apache.commons.logging.LogFactory
or
org.apache.commons.logging.Log
.
org.apache.commons.logging.LogFactory
or
org.apache.commons.logging.Log
.
I am happy to report that future versions of Jetty are expected to drop JCL in favor of SLF4J. However, for older versions of Jetty, the following instructions should get you going.
org.apache.commons.logging.LogFactory
to
org.apache.commons.logging.impl.LogFactoryImpl
. This
can be accomplished by starting Jetty as follows on the command line:
java -Dorg.apache.commons.logging.LogFactory=org.apache.commons.logging.impl.LogFactoryImpl \ -jar start.jar
org.apache.commons.logging.Log
system property.
As demonstrated above, JCL's discovery mechanism invents new and original ways of shooting yourself in the foot. For example, with JCL you can shoot yourself in the foot while aiming at the sky. Thanks to JCL you can be hit by lightning in the middle of the desert when it's not raining. If your computing life is too dull and trouble is what you are looking for, then JCL is the way to go.
In summary, statically bound discovery provides better
functionality, with none of the painful bugs associated with
JCL's dynamic discovery.
In order for JCL to reliably discover a logging API,
this API must be located at the same level or higher in the
class loader tree. Thus, in practical terms, the only logging
API safely bridged by JCL is the
java.util.logging
API. When compared with a
statically bound bridging mechanism, for example as implemented
by SLF4J, JCL's dynamic
discovery mechanism has strictly zero added value. In summary,
statically bound discovery provides better functionality, with
none of the painful bugs associated with JCL's dynamic
discovery.
As many Apache components rely on JCL, many developers inside and outside Apache are fooled into thinking that using JCL is safe and innocuous. Such developers assume that since a large number of projects already use JCL, it cannot suffer from any serious bugs because such bugs would have been previously reported and presumably corrected. As Eric S. Raymond put it, "given enough eyeballs, all bugs are shallow."
There is no doubt that as the number of eyeballs increases, the probability of catching bugs increases as well. However, we implicitly equate eyeballs with users of software. Unfortunately, the vast majority of users of any given software do not look at the software they are using, at least not in a serious and meaningful way. In reality the improvement in catching bugs is only logarithmic with the number of users.
The fact that many people suffer the effects of a bug does not mean they will report it, let alone research it.
The nature of the bug also plays a crucial role in its identification. Humans are good at hunting down bugs that they can see. However, humans are not mentally equipped to identify class loader bugs which depend on factors external to the code being examined. Even an experienced and competent developer can stare at a class loader bug for hours and still not realize that it is there. It takes the precision of a JVM and a lot of patience to hunt down class loader bugs which are likely to remain elusive for the foreseeable future.