Bug 9305 - Use thread context class loader for loading
Use thread context class loader for loading
Status: RESOLVED FIXED
Product: Log4j
Classification: Unclassified
Component: Configurator
1.2
All All
: P3 enhancement
: ---
Assigned To: log4j-dev
:
Depends on:
Blocks:
  Show dependency tree
 
Reported: 2002-05-22 06:41 UTC by Scott M Stark
Modified: 2004-11-16 19:05 UTC (History)
0 users



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Scott M Stark 2002-05-22 06:41:13 UTC
The current use of Class.forName in classes like 
org.apache.log4j.xml.DOMConfigurator restrict flexibility of how appenders, 
filters, etc. may be loaded into the VM. When used in an application server 
this forces all dynamcially loaded objects to be in the same classpath 
namespace that loaded the log4j.jar. There is no drawback to using the thread 
context class loader instance of Class.forName and there are many advantages.
Comment 1 Scott M Stark 2002-05-22 07:12:26 UTC
There is one drawback to accessing the thread context class loader. It is a 
privaledged operation that can result in a SecurityException. The same 
flexibility can be achieved by allowing one to set the ClassLoader the 
configurator uses to load classes. Then the caller can decide to use the
thread context class loader or whatever loader they choose.
Comment 2 Ceki Gulcu 2002-05-22 08:29:23 UTC
Scott,

I'm on this. Will reply fully in 30 minutes.

--
Ceki
Comment 3 Ceki Gulcu 2002-05-22 09:22:45 UTC
Scott,

This what I started writing:

--- BEGIN ----------------
The following is from the docs/HISTORY file

  Release of log4j-1.2beta4

  - Replaced the custom class loading based on the thread context class
    loader with a simple Class.forName() call. This solves two allied
    but distinct problems encountered when using Ant with JUnit
    although the bug is more general. In one instance of the
    problem, log4j would throw java.lang.NoClassDefFoundError for
    org/apache/log4j/AppenderSkeleton where log4j.jar and related
    classes were clearly available to the Ant classloader. In another
    incarnation, log4j would reject a custom appender claiming that it is
    not assignable to a org.apache.log4j.Appender variable. This would
    occur when log4j.jar was available to both the Ant classloader and the
    system classloader. 
    
    Thanks to Dave Herman for providing detailed scenarios exposing
    the issues involved. See
      http://forum.java.sun.com/thread.jsp?forum=38&thread=70946
      http://forum.java.sun.com/thread.jsp?forum=38&thread=70946#479697
      http://marc.theaimsgroup.com/?l=ant-user&m=101139178705895&w=2
    for more details. [*]

In conclusion, while loading classes through the context class loader
has advantages, it also has disadvantages. I would like to learn more
about the exact scenario you are confronted with before making a
decision. Moreover, please be more specific about the "many
advantages" you see.

--- END ---------------------

Then I started reading the discussion threads on forum.java.sun.com to
check whether the fix in log4j-1.2beta4 still made sense. (Until
log4j-1.2beta4, alpha and beta versions of log4j used the context
class loader.)

Fortunately, I also had test cases reproducing the issues that Dave
Herman had observed. In one scenario, log4j-1.2beta2.jar was available
to the ANT class loader but not to the system class loader. Still in
the same scenario, a custom appender, named foo.MyAppender, would be
available to system class loader but not to the ANT class loader.

In this scenario, running a simple test case that tried to configure
log4j by instantiating foo.MyAppender and adding it to the root logger
would fail with the following error.

junit:
    [junit] Running foo.junit.MyTestCase
    [junit] Tests run: 1, Failures: 0, Errors: 1, Time elapsed: 0.05 sec
    [junit] Output:
    [junit] debug: Test case <= org.apache.tools.ant.AntClassLoader
    [junit] debug: Thread context <= sun.misc.Launcher$AppClassLoader
    [junit]
    [junit] Testsuite: foo.junit.MyTestCase
    [junit] Tests run: 1, Failures: 0, Errors: 1, Time elapsed: 0.05 sec
    [junit] ------------- Standard Output ---------------
    [junit] debug: Test case <= org.apache.tools.ant.AntClassLoader
    [junit] debug: Thread context <= sun.misc.Launcher$AppClassLoader
    [junit] ------------- ---------------- ---------------
    [junit]
    [junit] Testcase: testCustomAppender took 0.04 sec
    [junit]     Caused an ERROR
    [junit] org/apache/log4j/AppenderSkeleton
    [junit] java.lang.NoClassDefFoundError: org/apache/log4j/AppenderSkeleton
    [junit]     at java.lang.ClassLoader.defineClass0(Native Method)
  <snip>
    [junit]     at java.security.AccessController.doPrivileged(Native Method)
    [junit]     at java.net.URLClassLoader.findClass(URLClassLoader.java:188)
    [junit]     at java.lang.ClassLoader.loadClass(ClassLoader.java:297)
    [junit]     at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:286)
    [junit]     at java.lang.ClassLoader.loadClass(ClassLoader.java:253)
    [junit]     at org.apache.log4j.helpers.Loader.loadClass(Loader.java:124)
    [junit]     at 
org.apache.log4j.helpers.OptionConverter.instantiateByClassName
(OptionConverter.java:313)
    [junit]     at org.apache.log4j.helpers.OptionConverter.instantiateByKey
(OptionConverter.java:116)
    [junit]     at org.apache.log4j.PropertyConfigurator.parseAppender
(PropertyConfigurator.java:619)
  <snip>

So AppenderSkeleton could not be found because log4j-1.2beta2.jar was
not available to the system class loader and as no context class loader
was set, the context class loader used defaulted to the system
class loader.

As I said previously, changing log4j code to use only Class.forName
for class loading solves the above problem since both
log4j-1.2beta2.jar and foo.MyAppender are available to the ANT
class loader and its parent the system class loader.

In the original scenario that Dave Herman had in mind, both the system
class loader and the ANT class loader had log4j-1.2beta2.jar available
to them but only the system class loader had foo.MyAppender
available. Running this would result in the following error:

junit:
    [junit] Running foo.junit.MyTestCase
    [junit] Tests run: 1, Failures: 1, Errors: 0, Time elapsed: 0.05 sec
    [junit] Error:
    [junit] debug: Test case <= org.apache.tools.ant.AntClassLoader
    [junit] debug: Thread context <= sun.misc.Launcher$AppClassLoader
    [junit] log4j:ERROR A "foo.MyAppender" object is not assignable to 
a "org.apache.log4j.Appender" variable.
    [junit] log4j:ERROR Could not instantiate appender named "Foo".
     <snip>

In this case, log4j refused to use foo.MyAppender because it was not
assignable to o.a.log4j.Appender. This can be explained by the fact
that log4j's copy of o.a.log4j.Appender was loaded by the ANT class
loader whereas the foo.MyAppender was loaded by the system class
loader. 

Simply ignoring the context loader and using only Class.forName also
fixed this scenario.

So I was "tricked" into thinking that Class.forName was the way to
go. What I did not realize was that there was a bug in our
implementation of o.a.log4j.helpers.Loader.loadClass() method which
was ultimately responsible to loading classes.

The implementation was:

 /**
     Load the specified class using the <code>Thread</code>
     <code>contextClassLoader</code> if running under Java2 or current
     class loader if running under JDK 1.1.
  */
  static
  public 
  Class loadClass (String clazz) throws ClassNotFoundException {
    if(java1) {
      return Class.forName(clazz);
    } else {
      try {
	return Thread.currentThread().getContextClassLoader().loadClass(clazz);
      } catch(Exception e) {
	// we reached here because
	// currentThread().getContextClassLoader() is null or because
	// of a security exceptio, or because clazz could not be
	// loaded, in any case we now try one more time
	return Class.forName(clazz);
      }
    }
  } 

This implementation is sub optimal first because it does not compile
with JDK 1.1 and more importantly because it is buggy. The
java.lang.NoClassDefFoundError (see first scenario above) is not an
Exception but an Error. This means that the code within the catch
block will never be executed. 

Changing the Loader.loadClass code to

  static
  public 
  Class loadClass (String clazz) throws ClassNotFoundException {
    if(java1) {
      return Class.forName(clazz);
    } else {
      try {
	return Thread.currentThread().getContextClassLoader().loadClass(clazz);
      } catch(Throwable e) {  // <-- was originally Exception
	return Class.forName(clazz);
      }
    }
  } 
}

solves the problem encountered in scenario one. It does not solve the
problem encountered in the second scenario.

More generally, if log4j-XX.jar is available to both the context class
loader as well as to the class loader that loaded the code currently
being executed, then a log4j component (e.g. an appender) may be
loaded by the context class loader such that it is incompatible with
the log4j classes loaded by the class loader that loaded the code
currently being executed.

How far fetched is this scenario? Well, I am almost convinced that
someone will come up with a case where it looks perfectly legitimate.

To make a long story short, I still would like to learn more about the
exact scenario you are confronted with before making a decision.
Comment 4 Scott M Stark 2002-05-22 09:35:48 UTC
My response is that there is no need to choose Class.forName or the TCL. Simply
add a setClassLoader(ClassLoader loader) method to the configurator and then it 
is the framework user's choice of how the framework integrates with its usage 
context class loading policy. Default the configurator loader to getClass
().getClassLoader() and there is no change in behavior by default.

As to examples of where Class.forName fails:
1. Bootstrap a minimal app server with a minimal configuration with the 
log4j.jar in the classpath
2. Load the full app server configuration from a remote web server. This 
includes an extended log4j configuration and any number of filters, appenders, 
etc. that are loaded by the URLClassLoader associated with the web server. This 
is a child of the class loader used during the bootstrap and so its classes are 
not visible to Class.forName invocations made from the log4j.jar classes.
Comment 5 Ceki Gulcu 2002-05-22 10:35:02 UTC
> My response is that there is no need to choose Class.forName or the
> TCL. Simply add a setClassLoader(ClassLoader loader) method to the
> configurator and then it is the framework user's choice of how the
> framework integrates with its usage context class loading
> policy. Default the configurator loader to getClass
> ().getClassLoader() and there is no change in behavior by default.

Sounds very reasonable.
 
> As to examples of where Class.forName fails: 1. Bootstrap a minimal
> app server with a minimal configuration with the log4j.jar in the
> classpath 2. Load the full app server configuration from a remote web
> server. This includes an extended log4j configuration and any number
> of filters, appenders, etc. that are loaded by the URLClassLoader
> associated with the web server. This is a child of the class loader
> used during the bootstrap and so its classes are not visible to
> Class.forName invocations made from the log4j.jar classes.

If I undestand correctly, the bootstrap server will load a simple
log4j config, create a URLClassLoader, and reconconfigure log4j with a
more sophisticated configuration loaded by the URLClassLoader.  Is
that correct?

Now, assuming the TCL was set to the URLClassLoader, if log4j
configurators used the TCL to load and instantiate classes by name,
this would also work for you. Yes?

Thus, we have three alternatives.

1) Log4j configurators use the class loader specified by the user, as
you just suggested.

2) Log4j configurators use the TCL as a first alternative and only
then Class.forName.

3) Use the CL specified by the user. If none is specified, revert to
2.

I am inclined to offer just 2 immediately and 3 at a later
stage. Would that be good enough for you?
Comment 6 Scott M Stark 2002-05-22 16:00:48 UTC
Option 2 works fine as I can just as easily ensure the TCL is correct.
Comment 7 Ceki Gulcu 2002-06-10 17:31:08 UTC
No news, good news. Closing the report.