My thought was that any contribution I might make would involve code changes, but have since discovered that 1) changes already made in JCL 1.0.5RC1 already represent a significant improvement, and 2) distributing a commons-logging-impl.jar (comprising the pieces missing from commons-logging-api.jar) can go a long way toward resolving the remaining issues. Given that, it seems useful to publish what I have found so far. I’d be very grateful for any comments, suggestions or corrections. Please feel free to send them to bes_commons_devNOSPAM AT yahoo DOT com.
The discussion below is based on Ceki’s original test case distribution plus some additional tests that I developed for this analysis. To run these tests, simply unzip Ceki’s distribution and then unzip my distribution into the same directory. My distribution provides the following:
1) A replacement of the JCL 1.0.4 jars used in Ceki’s analysis with the jars from JCL 1.0.5RC1.
2) commons-logging-impl.jar and commons-logging-api-log4j.jar, which are simply other ways of packaging the JCL classes, as discussed in Improvements Possible With New Packaging Options below.
3) Some new test cases.
4) Various config files (i.e. commons-logging.properties and log4j.properties) used in demonstrating the ability to specify different logging implementations in a parent classloader vs. a child classloader.
The JCL version included in Ceki Gülcü’s test setup was 1.0.4. Changes made in JCL in preparation for release 1.0.5 have at least partially resolved a number of the issues he identified. In general JCL 1.0.5RC1 is much less likely to throw a LogConfigurationException, but still tends to default to JDK 1.4 logging in situations where a user might reasonably expect log4j or some other logging implementation would be discovered.
The following summarizes the various test cases in Ceki Gülcü’s analysis, with a comment on the effect of using 1.0.5RC1. The headings (“Example 1”, “Example 2”, etc) refer to the examples in Ceki’s document.
Problem : With parent-first classloader, if TCCL is not set, log4j available in child loader is not seen, so logging is done via JDK 1.4 logging.
To Reproduce, Run:
java -cp boxAPI.jar;classes;lib/commons-logging.jar ch.qos.test.ParentFirstTestJCL0
With JCL 1.0.5RC1: No change.
Problem: With parent-first classloader, if TCCL is set and log4j is available in the child loader, a LogConfigurationException (cause: NoClassDefFoundError) is thrown when Log4JLogger found by parent loader cannot find Log4j.
To Reproduce, Run:
java -cp boxAPI.jar;classes;lib/commons-logging.jar ch.qos.test.ParentFirstTestJCL1
With JCL 1.0.5RC1: No longer throws an exception, but logging is done via JDK 1.4 logger.
Problem: With parent-first classloader if TCCL is set and log4j is available in the child loader, making only commons-logging-api.jar available to the parent allows log4j logging in the child, but prevents it in the parent.
To Reproduce, Run:
java -cp boxAPI.jar;classes;lib/commons-logging-api.jar ch.qos.test.ParentFirstTestJCL1
With JCL 1.0.5RC1: No change.
Problem: With parent-first classloader if TCCL is set and log4j is available in the child loader, a LogConfigurationException is thrown when a class loaded by the parent loader attempts to log via JCL.
To Reproduce, Run:
java -cp boxAPI.jar;classes;lib/commons-logging.jar ch.qos.test.ParentFirstTestJCL2
With JCL 1.0.5RC1: Fixed.
Problem: With child-first classloader, if both parent and child loaders have access to commons-logging.jar and TCCL points to the child loader, LogConfigurationException is thrown whenever a class loaded by the parent invokes LogFactory.getLog.
To Reproduce, Run:
java -cp classes;lib/commons-logging.jar ch.qos.test.ChildFirstTestJCL0
With JCL 1.0.5RC1: No change.
Synopsis: With child-first classloader, if both parent and child loaders have access to commons-logging.jar, class loaded by the child loader is able to log. This example wasn’t intended to show a problem, but rather an area where JCL worked as expected.
To Reproduce, Run:
java -cp boxAPI.jar;classes;lib/commons-logging.jar ch.qos.test.ChildFirstTestJCL1
Problem: With child-first classloader, if only the parent has access to commons-logging.jar and only the child has access to log4j, LogConfigurationException is thrown whenever a class loaded by the child invokes LogFactory.getLog.
To Reproduce, Run:
java -cp classes;boxAPI.jar;lib/commons-logging.jar ch.qos.test.ChildFirstTestJCL2
With JCL 1.0.5RC1: No longer throws an exception, but logging is done via JDK 1.4 logger.
Problem: With child-first classloader, if only the parent has access to commons-logging.jar and only the child has access to log4j, LogConfigurationException is thrown whenever a class loaded by the parent invokes LogFactory.getLog.
To Reproduce, Run:
java -cp classes;boxAPI.jar;lib/commons-logging.jar ch.qos.test.ChildFirstTestJCL3
With JCL 1.0.5RC1: No longer throws an exception, but logging is done via JDK 1.4 logger.
I thought it might be useful to more fully explore the different logging configuration options that are possible with the current JCL packaging options. This section introduces a number of new tests that show exactly which logging options work and which don’t in a parent-first classloading environment. I do this both for the sake of fully illustrating the issues for readers who are less familiar with JCL and with a view toward coming up with a fairly complete set of use cases against which JCL or other alternatives like UGLI can be evaluated.
For those not interested in the gory details, here’s a summary so you can skip ahead to the next section:
1) If both parent and child want to use the same logging implementation, this can be configured (see Example 8 and 8-B below).
2) If child wants to use non-JDK 1.4 logging, and the parent wants JDK 1.4 logging, this can be configured (see Example 2-B above).
3) If the parent wants non-JDK 1.4 logging and the child wants JDK 1.4 logging, this can be configured (see Example 9 below).
4) If the parent wants non-JDK 1.4 logging and the child wants a different non-JDK 1.4 logging, this CANNOT be configured (see Example 10 below).
This example demonstrates that in a parent-first classloading situation simply making commons-logging.jar and log4j.jar available to the parent classloader allows log4j logging no matter whether the parent or the child is the TCCL.
public class ParentFirstTestJCL3 {
public static void main(String[] args) throws Exception {
URLClassLoader childClassLoader =
new URLClassLoader(
new URL[] {
new URL("file:box1.jar)
});
ClassLoader origClassLoader = Thread.currentThread().getContextClassLoader();
Thread.currentThread().setContextClassLoader(childClassLoader);
Class versionClass1 = childClassLoader.loadClass("box.BoxImplWithJCL");
Box box = (Box) versionClass1.newInstance();
box.doOp();
Log log = LogFactory.getLog("main in TCCL");
log.info("got log " + log.getClass().getName());
Thread.currentThread().setContextClassLoader(origClassLoader);
log = LogFactory.getLog("main in sys loader");
log.info("got log " + log.getClass().getName());
}
}
java -cp boxAPI.jar;classes;lib/commons-logging.jar;lib/log4j.jar;lib/log4j com.wanconcepts.jcl.ParentFirstTestJCL3
Result:
All logging is done via log4j.
This test makes commons-logging.jar and log4j.jar available to both the parent and child classloaders and shows that both can log using log4j; in other words deploying in both places does not break anything.
public class ParentFirstTestJCL4 {
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")
});
ClassLoader origClassLoader = Thread.currentThread().getContextClassLoader();
Thread.currentThread().setContextClassLoader(childClassLoader);
Class versionClass1 = childClassLoader.loadClass("box.BoxImplWithJCL");
Box box = (Box) versionClass1.newInstance();
box.doOp();
Log log = LogFactory.getLog("main in TCCL");
log.info("got log " + log.getClass().getName());
Thread.currentThread().setContextClassLoader(origClassLoader);
log = LogFactory.getLog("main in sys loader");
log.info("got log " + log.getClass().getName());
}
}
java -cp boxAPI.jar;classes;lib/commons-logging.jar;lib/log4j.jar;lib/log4j com.wanconcepts.jcl.ParentFirstestJCL4
Result:
All logging is done via log4j.
This example shows that in a parent-first classloading situation, if the parent wants log4j logging and the child wants JDK 1.4 logging, this can be accomplished by having an appropriate commons-logging.properties file available to the child loader.
public class ParentFirstTestJCL5 {
public static void main(String[] args) throws Exception {
URLClassLoader childClassLoader =
new URLClassLoader(
new URL[] {
new URL("file:box1.jar"),
new URL("file:lib/jdk14/")
});
ClassLoader origClassLoader = Thread.currentThread().getContextClassLoader();
Thread.currentThread().setContextClassLoader(childClassLoader);
Class versionClass1 = childClassLoader.loadClass("box.BoxImplWithJCL");
Box box = (Box) versionClass1.newInstance();
box.doOp();
Log log = LogFactory.getLog("main in TCCL");
log.info("got log " + log.getClass().getName());
Thread.currentThread().setContextClassLoader(origClassLoader);
log = LogFactory.getLog("main in sys loader");
log.info("got log " + log.getClass().getName());
}
}
java -cp boxAPI.jar;classes;lib/commons-logging.jar;lib/log4j.jar;lib/log4j com.wanconcepts.jcl.ParentFirstTestJCL5
Result:
Logging from classes loaded by the parent loader is done via log4j while logging from classes loaded from the child loader is done via JDK 1.4.
This example shows that in a parent-first classloading situation a LogConfigurationException will be thrown if the parent and child loaders attempt to use different non-JDK 1.4 logging implementations.
public class ParentFirstTestJCL6 {
public static void main(String[] args) throws Exception {
URLClassLoader childClassLoader =
new URLClassLoader(
new URL[] {
new URL("file:box1.jar"),
new URL("file:lib/logkit/"),
new URL("file:lib/avalon-logkit-2.0.dev-0.jar")
});
ClassLoader origClassLoader = Thread.currentThread().getContextClassLoader();
Thread.currentThread().setContextClassLoader(childClassLoader);
Class versionClass1 = childClassLoader.loadClass("box.BoxImplWithJCL");
Box box = (Box) versionClass1.newInstance();
box.doOp();
Log log = LogFactory.getLog("main in TCCL");
log.info("got log " + log.getClass().getName());
Thread.currentThread().setContextClassLoader(origClassLoader);
log = LogFactory.getLog("main in sys loader");
log.info("got log " + log.getClass().getName());
}
}
java -cp boxAPI.jar;classes;lib/commons-logging.jar;lib/log4j.jar;lib/log4j com.wanconcepts.jcl.ParentFirstTestJCL6
Result:
LogConfigurationException is thrown as the parent classloader is unable to discover the logkit jar.
The preceding discussion has focused on the improvements JCL 1.0.5RC1 has made in reducing the potential for exceptions being thrown due to JCL configuration problems. However, in many cases JCL ends up using JDK 1.4 logging when a user most likely wanted log4j or some other logging implementation.
This section discusses how most, if not all of the remaining problems can be addressed if deployments to a child classloader use a proposed “commons-logging-impl.jar” instead of commons-logging.jar. “commons-logging-impl.jar” packages the classes found in commons-logging.jar that are not found in commons-logging-api.jar – i.e. the wrappers for Log4j, Avalon and Logkit.
The examples below are numbered to correspond to the original example in Ceki’s analysis to which each is related. For instance, Example 4.i shows how use of commons-logging-impl.jar corrects the defect discussed in Ceki’s Example 4.
With a child-first classloader, if both parent and child loaders have access to commons-logging.jar and TCCL points to the child loader, LogConfigurationException is thrown whenever a class loaded by the parent invokes LogFactory.getLog. This example shows that if the child loader is only given access to commons-logging-impl, this is fixed.
public class ChildFirstTestJCL5 {
public static void main(String[] args) throws Exception {
ChildFirstClassLoader child = new ChildFirstClassLoader(
new URL[] { new URL("file:lib/commons-logging-impl.jar") });
Thread.currentThread().setContextClassLoader(child);
// JCL will not throw an exception
Log log = LogFactory.getLog("main in TCCL");
log.info("got log " + log.getClass().getName());
}
java -cp classes;lib/commons-logging.jar com.wanconcepts.jcl.ChildFirstTestJCL5
Result:
No exception thrown; logging is done (as configured) via JDK 1.4.
This example goes beyond Example 4.i to demonstrate that with commons-logging-impl, not only will no exception be thrown, but also that it is possible to log with two different non-JDK loggers (e.g. log4j at the parent level and Avalon at the child level).
public class ChildFirstTestJCL6 {
public static void main(String[] args) throws Exception {
ChildFirstClassLoader child = new ChildFirstClassLoader(
new URL[] {
new URL("file:lib/commons-logging-impl.jar"),
new URL("file:lib/logkit/"),
new URL("file:lib/avalon-logkit-2.0.dev-0.jar")
});
ClassLoader origClassLoader = Thread.currentThread().getContextClassLoader();
Thread.currentThread().setContextClassLoader(child);
Log log = LogFactory.getLog("main in TCCL");
log.info("got log " + log.getClass().getName());
Thread.currentThread().setContextClassLoader(origClassLoader);
log = LogFactory.getLog("main in sys loader");
log.info("got log " + log.getClass().getName());
}
}
Run:
java -cp classes;lib/commons-logging.jar;lib/log4j.jar;lib/log4j com.wanconcepts.jcl.ChildFirstTestJCL6
Result:
Parent level logging uses log4j and child level logging uses Avalon Logkit.
In Example 5, we saw that if commons-logging.jar was not available to the child loader but log4j was, with JCL 1.0.5RC1 no exception would be thrown but that logging would use the JDK logger. Presumably the reason commons-logging.jar would not be available to the child loader would be because it was not deployed in order to avoid conflicts with a JCL deployment at the parent loader level. This example shows that if commons-logging-impl.jar is made accessible at the child level, logging occurs via log4j.
public class ChildFirstTestJCL8 {
public static void main(String[] args) throws Exception {
ChildFirstClassLoader child = new ChildFirstClassLoader(new URL[] {
new URL("file:box1.jar"),
new URL("file:lib/commons-logging-impl.jar"),
new URL("file:lib/log4j.jar"),
new URL("file:lib/log4j/") });
Thread.currentThread().setContextClassLoader(child);
Class boxClass = child.loadClass("box.BoxImplWithJCL");
Box box = (Box) boxClass.newInstance();
box.doOp();
}
}
Run:
java -cp classes;boxAPI.jar;lib/commons-logging.jar com.wanconcepts.jcl.ChildFirstTestJCL8
Result:
Child level logging uses log4j.
Running ChildFirstTestJCL9 basically shows the same thing as Example 5.i – when the TCCL is the child loader, logging will, as expected, be done via log4j.
public class ChildFirstTestJCL9 {
public static void main(String[] args) throws Exception {
ChildFirstClassLoader child = new ChildFirstClassLoader(new URL[] {
new URL("file:box1.jar"),
new URL("file:lib/commons-logging-impl.jar"),
new URL("file:lib/log4j.jar"),
new URL("file:lib/log4j/") });
Thread.currentThread().setContextClassLoader(child);
Log log = LogFactory.getLog("child loader");
log.info("got log " + log.getClass().getName());
}
}
Run:
java -cp classes;boxAPI.jar;lib/commons-logging.jar com.wanconcepts.jcl.ChildFirstTestJCL9
Result:
The above examples have shown that using commons-logging-impl.jar at the child level allows proper behavior in child-first classloading situations. It has previously been shown that in parent-first classloading situations, JCL can be configured to work appropriately except when the parent and child wish to use different non-JDK logging implementations.
This last example shows that this limitation can also be overcome if yet another packaging of the JCL classes is used at the parent level. In this case, the parent should deploy a version of commons-logging-api.jar that has been altered to include the wrapper implementation desired for use at the parent level. An example of such a jar can be found in the distribution as “commons-logging-api-log4j.jar”. Children would then deploy commons-logging-impl.jar.
To demonstrate this, the test executed in Example 10 can be re-run, but with the system classpath altered to use “commons-logging-api-log4j.jar”.
Run:
java -cp boxAPI.jar;classes;lib/commons-logging-api-log4j.jar;lib/log4j.jar;lib/log4j com.wanconcepts.jcl.ParentFirstTestJCL6
Result:
No exception thrown. Parent level logging uses log4j and child level logging uses Avalon Logkit.
JCL 1.0.5RC1 goes a long way toward resolving the various classloading problems associated with JCL. By including some additional packaging options, JCL could potentially resolve many more. Forcing users choose the correct JCL package is certainly not ideal. However, the following decision matrix might be useful in helping users:
For users deploying classes that will be loaded by a child loader:
Will JCL be loaded by a parent classloader?
YES: deploy commons-logging-impl.jar
NO: deploy commons-logging.jar
For users deploying deploying classes that will be loaded by a parent classloader:
Will child classloaders use a child-first delegation model?
YES: deploy commons-logging.jar
NO: do you want to give children the ability to choose their own logging impl?
YES: deploy a special commons-logging-api-xxx.jar that includes the
Log implementation you want to use at the parent level.
NO: deploy commons-logging.jar
Such complexity is not particularly desirable, but at least the most difficult aspect is restricted to the parent loader level, where it might be expected that the users have greater understanding of classloading issues.
A few thoughts come to mind regarding further work that can be done in this area:
1) Tests duplicating most of the above examples should be added to the JCL unit test suite.
2) It would be useful to draw up a matrix showing how JCL, both with a simple configuration and the more complex configurations discussed above, compares to UGLI in the above examples.
3) Tests of other classloading configurations. One that comes to mind is war-ear-server, where a child-first loader is a war is below a parent-first loader in an ear, which is below a server classloader, all using JCL.
Again, any thoughts or comments would be most welcome at bes_commons_devNOSPAM AT yahoo DOT com.