+ * If a system property of this name is set then the value is + * assumed to be the name of a file. The special strings + * STDOUT or STDERR (case-sensitive) indicate output to + * System.out and System.err respectively. + */ + public static final String DIAGNOSTICS_DEST_PROPERTY = + "org.apache.commons.logging.diagnostics.dest"; + + /** + * When null (the usual case), no diagnostic output will be + * generated by LogFactory or LogFactoryImpl. When non-null, + * interesting events will be written to the specified object. + */ + private static PrintStream diagnosticsStream = null; + + /** + * A string that gets prefixed to every message output by the + * logDiagnostic method, so that users can clearly see which + * LogFactory class is generating the output. + */ + private static String diagnosticPrefix; + /** *
Setting this system property value allows the Hashtable used to store
* classloaders to be substituted by an alternative implementation.
@@ -133,10 +163,9 @@ public abstract class LogFactory {
/**
* Protected constructor that is not available for public use.
*/
- protected LogFactory() {
+ protected LogFactory() {
}
-
-
+
// --------------------------------------------------------- Public Methods
@@ -247,6 +276,21 @@ public abstract class LogFactory {
*/
protected static LogFactory nullClassLoaderFactory = null;
+ /**
+ * Create the hashtable which will be used to store a map of
+ * (context-classloader -> logfactory-object). Version 1.2+ of Java
+ * supports "weak references", allowing a custom Hashtable class
+ * to be used which uses only weak references to its keys. Using weak
+ * references can fix memory leaks on webapp unload in some cases (though
+ * not all). Version 1.1 of Java does not support weak references, so we
+ * must dynamically determine which we are using. And just for fun, this
+ * code also supports the ability for a system property to specify an
+ * arbitrary Hashtable implementation name.
+ *
+ * Note that the correct way to ensure no memory leaks occur is to ensure + * that LogFactory.release(contextClassLoader) is called whenever a + * webapp is undeployed. + */ private static final Hashtable createFactoryStore() { Hashtable result = null; String storeImplementationClass @@ -260,9 +304,16 @@ public abstract class LogFactory { } catch (Throwable t) { // ignore - if (!WEAK_HASHTABLE_CLASSNAME.equals(storeImplementationClass)) { - // if the user's trying to set up a custom implementation, give a clue - System.err.println("[ERROR] LogFactory: Load of custom hashtable failed"); + if (!WEAK_HASHTABLE_CLASSNAME.equals(storeImplementationClass)) { + // if the user's trying to set up a custom implementation, give a clue + if (isDiagnosticsEnabled()) { + // use internal logging to issue the warning + logDiagnostic("[ERROR] LogFactory: Load of custom hashtable failed"); + } else { + // we *really* want this output, even if diagnostics weren't + // explicitly enabled by the user. + System.err.println("[ERROR] LogFactory: Load of custom hashtable failed"); + } } } if (result == null) { @@ -305,13 +356,32 @@ public abstract class LogFactory { // Identify the class loader we will be using ClassLoader contextClassLoader = getContextClassLoader(); + if (contextClassLoader == null) { + // This is an odd enough situation to report about. This + // output will be a nuisance on JDK1.1, as the system + // classloader is null in that environment. + logDiagnostic("Context classloader is null."); + } + // Return any previously registered factory for this class loader LogFactory factory = getCachedFactory(contextClassLoader); - if (factory != null) + if (factory != null) { return factory; + } + + logDiagnostic( + "LogFactory requested for the first time for context classloader " + + objectId(contextClassLoader)); // Load properties file. - // Will be used one way or another in the end. + // + // If the properties file exists, then its contents are used as + // "attributes" on the LogFactory implementation class. One particular + // property may also control which LogFactory concrete subclass is + // used, but only if other discovery mechanisms fail.. + // + // As the properties file (if it exists) will be used one way or + // another in the end we may as well look for it first. Properties props=null; try { @@ -324,28 +394,47 @@ public abstract class LogFactory { stream.close(); } } catch (IOException e) { + ; // ignore } catch (SecurityException e) { + ; // ignore } - // First, try the system property + // First, try a global system property + logDiagnostic( + "Looking for system property [" + FACTORY_PROPERTY + + "] to define the LogFactory subclass to use.."); + try { String factoryClass = System.getProperty(FACTORY_PROPERTY); if (factoryClass != null) { - factory = newFactory(factoryClass, contextClassLoader); + logDiagnostic( + "Creating an instance of LogFactory class " + factoryClass + + " as specified by system property " + FACTORY_PROPERTY); + + factory = newFactory(factoryClass, contextClassLoader, contextClassLoader); } } catch (SecurityException e) { + logDiagnostic( + "A security exception occurred while trying to create an" + + " instance of the custom factory class" + + ": [" + e.getMessage().trim() + + "]. Trying alternative implementations.."); ; // ignore } - // Second, try to find a service by using the JDK1.3 jar - // discovery mechanism. This will allow users to plug a logger - // by just placing it in the lib/ directory of the webapp ( or in - // CLASSPATH or equivalent ). This is similar to the second - // step, except that it uses the (standard?) jdk1.3 location in the jar. + // Second, try to find a service by using the JDK1.3 class + // discovery mechanism, which involves putting a file with the name + // of an interface class in the META-INF/services directory, where the + // contents of the file is a single line specifying a concrete class + // that implements the desired interface. if (factory == null) { + logDiagnostic( + "Looking for a resource file of name [" + SERVICE_ID + + "] to define the LogFactory subclass to use.."); + try { InputStream is = getResourceAsStream(contextClassLoader, SERVICE_ID); @@ -366,11 +455,23 @@ public abstract class LogFactory { if (factoryClassName != null && ! "".equals(factoryClassName)) { - factory= newFactory( factoryClassName, contextClassLoader ); + logDiagnostic( + "Creating an instance of LogFactory class " + factoryClassName + + " as specified by file " + SERVICE_ID + + " which was present in the path of the context" + + " classloader."); + + factory = newFactory( factoryClassName, contextClassLoader, contextClassLoader ); } } } catch( Exception ex ) { - ; + logDiagnostic( + "A security exception occurred while trying to create an" + + " instance of the custom factory class" + + ": [" + ex.getMessage().trim() + + "]. Trying alternative implementations.."); + + ; // ignore } } @@ -383,10 +484,23 @@ public abstract class LogFactory { // the webapp, even if a default logger is set at JVM level by a // system property ) - if (factory == null && props != null) { - String factoryClass = props.getProperty(FACTORY_PROPERTY); - if (factoryClass != null) { - factory = newFactory(factoryClass, contextClassLoader); + if (factory == null) { + logDiagnostic( + "Looking for a properties file of name " + FACTORY_PROPERTIES + + " to define the LogFactory subclass to use.."); + + if (props != null) { + logDiagnostic( + "Properties file found. Looking for property " + + FACTORY_PROPERTY + + " to define the LogFactory subclass to use.."); + + String factoryClass = props.getProperty(FACTORY_PROPERTY); + if (factoryClass != null) { + factory = newFactory(factoryClass, contextClassLoader, contextClassLoader); + + // what about handling an exception from newFactory?? + } } } @@ -394,8 +508,21 @@ public abstract class LogFactory { // Fourth, try the fallback implementation class if (factory == null) { + logDiagnostic( + "Loading the default LogFactory implementation " + FACTORY_DEFAULT + + " via the same classloader that loaded this LogFactory" + + " class (ie not looking in the context classloader)."); + + // Note: we don't try to load the LogFactory implementation + // via the context classloader here because: + // * that can cause problems (see comments in newFactory method) + // * no-one should be customising the code of the default class + // Yes, we do give up the ability for the child to ship a newer + // version of the LogFactoryImpl class and have it used dynamically + // by an old LogFactory class in the parent, but that isn't + // necessarily a good idea anyway. ClassLoader logFactoryClassLoader = getClassLoader(LogFactory.class); - factory = newFactory(FACTORY_DEFAULT, logFactoryClassLoader); + factory = newFactory(FACTORY_DEFAULT, logFactoryClassLoader, contextClassLoader); } if (factory != null) { @@ -464,6 +591,7 @@ public abstract class LogFactory { */ public static void release(ClassLoader classLoader) { + logDiagnostic("Releasing factory for classloader " + objectId(classLoader)); synchronized (factories) { if (classLoader == null) { if (nullClassLoaderFactory != null) { @@ -492,6 +620,7 @@ public abstract class LogFactory { */ public static void releaseAll() { + logDiagnostic("Releasing factory for all classloaders."); synchronized (factories) { Enumeration elements = factories.elements(); while (elements.hasMoreElements()) { @@ -511,19 +640,16 @@ public abstract class LogFactory { // ------------------------------------------------------ Protected Methods - /** * Safely get access to the classloader for the specified class. *
- * Theoretically, calling Class.getClassLoader can throw a security - * exception, and so should be done under an AccessController in order - * to provide maximum flexibility. - *
- * However in practice people don't appear to use security policies that - * forbid getClassLoader calls, so for the moment this method doesn't - * bother to actually do that. As all code is written to call this - * method rather than Class.getClassLoader, AccessController stuff could - * be put in this method without any disruption later if needed. + * Theoretically, calling getClassLoader can throw a security exception, + * and so should be done under an AccessController in order to provide + * maximum flexibility. However in practice people don't appear to use + * security policies that forbid getClassLoader calls. So for the moment + * all code is written to call this method rather than Class.getClassLoader, + * so that we could put AccessController stuff in this method without any + * disruption later if we need to. *
* Even when using an AccessController, however, this method can still * throw SecurityException. Commons-logging basically relies on the @@ -539,10 +665,13 @@ public abstract class LogFactory { try { return clazz.getClassLoader(); } catch(SecurityException ex) { + logDiagnostic( + "Unable to get classloader for class " + clazz + + " due to security restrictions."); throw ex; } } - + /** * Calls LogFactory.directGetContextClassLoader under the control of an * AccessController class. This means that java code running under a @@ -637,6 +766,19 @@ public abstract class LogFactory { } catch (NoSuchMethodException e) { // Assume we are running on JDK 1.1 classLoader = getClassLoader(LogFactory.class); + + // We deliberately don't log a message here to outputStream; + // this message would be output for every call to LogFactory.getLog() + // when running on JDK1.1 + // + // if (outputStream != null) { + // outputStream.println( + // "Method Thread.getContextClassLoader does not exist;" + // + " assuming this is JDK 1.1, and that the context" + // + " classloader is the same as the class that loaded" + // + " the concrete LogFactory class."); + // } + } // Return the selected class loader @@ -646,6 +788,13 @@ public abstract class LogFactory { /** * Check cached factories (keyed by contextClassLoader) * + * @param contextClassLoader is the context classloader associated + * with the current thread. This allows separate LogFactory objects + * per component within a container, provided each component has + * a distinct context classloader set. This parameter may be null + * in JDK1.1, and in embedded systems where jcl-using code is + * placed in the bootclasspath. + * * @return the factory associated with the specified classloader if * one has previously been created, or null if this is the first time * we have seen this particular classloader. @@ -655,6 +804,9 @@ public abstract class LogFactory { LogFactory factory = null; if (contextClassLoader == null) { + // We have to handle this specially, as factories is a Hashtable + // and those don't accept null as a key value. + // // nb: nullClassLoaderFactory might be null. That's ok. factory = nullClassLoaderFactory; } else { @@ -693,7 +845,36 @@ public abstract class LogFactory { * implementation class, loaded by the specified class loader. * If that fails, try the class loader used to load this * (abstract) LogFactory. - * + *
+ *
+ * The problem is the same one that can occur when loading a concrete Log + * subclass via a context classloader. + *
+ * The problem occurs when code running in the context classloader calls + * class X which was loaded via a parent classloader, and class X then calls + * LogFactory.getFactory (either directly or via LogFactory.getLog). Because + * class X was loaded via the parent, it binds to LogFactory loaded via + * the parent. When the code in this method finds some LogFactoryYYYY + * class in the child (context) classloader, and there also happens to be a + * LogFactory class defined in the child classloader, then LogFactoryYYYY + * will be bound to LogFactory@childloader. It cannot be cast to + * LogFactory@parentloader, ie this method cannot return the object as + * the desired type. Note that it doesn't matter if the LogFactory class + * in the child classloader is identical to the LogFactory class in the + * parent classloader, they are not compatible. + *
+ * The solution taken here is to simply print out an error message when + * this occurs then throw an exception. The deployer of the application + * must ensure they remove all occurrences of the LogFactory class from + * the child classloader in order to resolve the issue. Note that they + * do not have to move the custom LogFactory subclass; that is ok as + * long as the only LogFactory class it can find to bind to is in the + * parent classloader. + *
* @param factoryClass Fully qualified name of the LogFactory
* implementation class
* @param classLoader ClassLoader from which to load this class
@@ -702,7 +883,8 @@ public abstract class LogFactory {
* cannot be created
*/
protected static LogFactory newFactory(final String factoryClass,
- final ClassLoader classLoader)
+ final ClassLoader classLoader,
+ final ClassLoader contextClassLoader)
throws LogConfigurationException
{
Object result = AccessController.doPrivileged(
@@ -712,8 +894,17 @@ public abstract class LogFactory {
}
});
- if (result instanceof LogConfigurationException)
- throw (LogConfigurationException)result;
+ if (result instanceof LogConfigurationException) {
+ LogConfigurationException ex = (LogConfigurationException) result;
+ logDiagnostic(
+ "An error occurred while loading the factory class:"
+ + ex.getMessage());
+ throw ex;
+ }
+
+ logDiagnostic(
+ "Created object " + objectId(result)
+ + " to manage classloader " + objectId(contextClassLoader));
return (LogFactory)result;
}
@@ -739,47 +930,80 @@ public abstract class LogFactory {
// Warning: must typecast here & allow exception
// to be generated/caught & recast properly.
logFactoryClass = classLoader.loadClass(factoryClass);
+ if (LogFactory.class.isAssignableFrom(logFactoryClass)) {
+ logDiagnostic(
+ "loaded class " + logFactoryClass.getName()
+ + " from classloader " + objectId(classLoader));
+ } else {
+ logDiagnostic(
+ "Factory class " + logFactoryClass.getName()
+ + " loaded from classloader " + objectId(classLoader)
+ + " does not extend " + LogFactory.class.getName()
+ + " as loaded by this classloader.");
+ }
+
return (LogFactory) logFactoryClass.newInstance();
} catch (ClassNotFoundException ex) {
if (classLoader == thisClassLoader) {
// Nothing more to try, onwards.
+ logDiagnostic(
+ "Unable to locate any class called " + factoryClass
+ + " via classloader " + objectId(classLoader));
throw ex;
}
// ignore exception, continue
} catch (NoClassDefFoundError e) {
if (classLoader == thisClassLoader) {
// Nothing more to try, onwards.
+ logDiagnostic(
+ "Class " + factoryClass + " cannot be loaded"
+ + " via classloader " + objectId(classLoader)
+ + ": it depends on some other class that cannot"
+ + " be found.");
throw e;
}
-
- } catch(ClassCastException e){
-
- if (classLoader == thisClassLoader) {
- // Nothing more to try, onwards (bug in loader implementation).
+ // ignore exception, continue
+ } catch(ClassCastException e) {
+ if (classLoader == thisClassLoader) {
+ // This cast exception is not due to classloader issues;
+ // the specified class *really* doesn't extend the
+ // required LogFactory base class.
+ logDiagnostic(
+ "Class " + factoryClass + " really does not extend "
+ + LogFactory.class.getName());
throw e;
- }
+ }
+ // Ignore exception, continue
}
- // Ignore exception, continue
}
/* At this point, either classLoader == null, OR
* classLoader was unable to load factoryClass.
- * Try the class loader that loaded this class:
- * LogFactory.getClassLoader().
+ *
+ * In either case, we call Class.forName, which is equivalent
+ * to LogFactory.class.getClassLoader.load(name), ie we ignore
+ * the classloader parameter the caller passed, and fall back
+ * to trying the classloader associated with this class. See the
+ * javadoc for the newFactory method for more info on the
+ * consequences of this.
*
* Notes:
- * a) LogFactory.class.getClassLoader() may return 'null'
- * if LogFactory is loaded by the bootstrap classloader.
- * b) The Java endorsed library mechanism is instead
- * Class.forName(factoryClass);
+ * * LogFactory.class.getClassLoader() may return 'null'
+ * if LogFactory is loaded by the bootstrap classloader.
*/
// Warning: must typecast here & allow exception
// to be generated/caught & recast properly.
+
+ logDiagnostic(
+ "Unable to load factory class via classloader "
+ + objectId(classLoader)
+ + ": trying the classloader associated with this LogFactory.");
logFactoryClass = Class.forName(factoryClass);
return (LogFactory) logFactoryClass.newInstance();
} catch (Exception e) {
// Check to see if we've got a bad configuration
+ logDiagnostic("Unable to create logfactory instance.");
if (logFactoryClass != null
&& !LogFactory.class.isAssignableFrom(logFactoryClass)) {
return new LogConfigurationException(
@@ -805,6 +1029,202 @@ public abstract class LogFactory {
}
});
}
+
+ /**
+ * Determines whether the user wants internal diagnostic output. If so,
+ * returns an appropriate writer object. Users can enable diagnostic
+ * output by setting the system property named OUTPUT_PROPERTY to
+ * a filename, or the special values STDOUT or STDERR.
+ */
+ private static void initDiagnostics() {
+ String dest;
+ try {
+ dest = System.getProperty(DIAGNOSTICS_DEST_PROPERTY);
+ if (dest == null) {
+ return;
+ }
+ } catch(SecurityException ex) {
+ // We must be running in some very secure environment.
+ // We just have to assume output is not wanted..
+ return;
+ }
+
+ if (dest.equals("STDOUT")) {
+ diagnosticsStream = System.out;
+ } else if (dest.equals("STDERR")) {
+ diagnosticsStream = System.err;
+ } else {
+ try {
+ // open the file in append mode
+ FileOutputStream fos = new FileOutputStream(dest, true);
+ diagnosticsStream = new PrintStream(fos);
+ } catch(IOException ex) {
+ // We should report this to the user - but how?
+ return;
+ }
+ }
+
+ // In order to avoid confusion where multiple instances of JCL are
+ // being used via different classloaders within the same app, we
+ // ensure each logged message has a prefix of form
+ // LogFactory@12345:
+ Class clazz = LogFactory.class;
+ String classLoaderName;
+ try {
+ ClassLoader classLoader = thisClassLoader;
+ if (thisClassLoader == null) {
+ classLoaderName = "BOOTLOADER";
+ } else {
+ classLoaderName = String.valueOf(System.identityHashCode(classLoader));
+ }
+ } catch(SecurityException e) {
+ classLoaderName = "UNKNOWN";
+ }
+ diagnosticPrefix =
+ clazz.getName() + "@" + classLoaderName + ": ";
+ }
+
+ /**
+ * Indicates true if the user has enabled internal logging.
+ *
+ * By the way, sorry for the incorrect grammar, but calling this method + * areDiagnosticsEnabled just isn't java beans style. + * + * @return true if calls to logDiagnostic will have any effect. + */ + protected static boolean isDiagnosticsEnabled() { + return diagnosticsStream != null; + } + + /** + * Write the specified message to the internal logging destination. + *
+ * Note that this method is private; concrete subclasses of this class + * should not call it because the diagnosticPrefix string this + * method puts in front of all its messages is LogFactory@...., + * while subclasses should put SomeSubClass@... + *
+ * Subclasses should instead compute their own prefix, then call + * logRawDiagnostic. Note that calling isDiagnosticsEnabled is + * fine for subclasses. + *
+ * Note that it is safe to call this method before initDiagnostics + * is called; any output will just be ignored (as isDiagnosticsEnabled + * will return false). + * + * @param msg is the diagnostic message to be output. + */ + private static final void logDiagnostic(String msg) { + if (diagnosticsStream != null) { + diagnosticsStream.print(diagnosticPrefix); + diagnosticsStream.println(msg); + diagnosticsStream.flush(); + } + } + + /** + * Write the specified message to the internal logging destination. + * + * @param msg is the diagnostic message to be output. + */ + protected static final void logRawDiagnostic(String msg) { + if (diagnosticsStream != null) { + diagnosticsStream.println(msg); + diagnosticsStream.flush(); + } + } + + /** + * Generate useful diagnostics regarding the classloader tree for + * the specified class. + *
+ * As an example, if the specified class was loaded via a webapp's + * classloader, then you may get the following output: + *
+ * Class com.acme.Foo was loaded via classloader 11111 + * ClassLoader tree: 11111 -> 22222 (SYSTEM) -> 33333 -> BOOT + *+ *
+ * This method returns immediately if isDiagnosticsEnabled() + * returns false. + * + * @param clazz is the class whose classloader + tree are to be + * output. + */ + private static void logClassLoaderTree(Class clazz) { + if (!isDiagnosticsEnabled()) { + return; + } + + String className = clazz.getName(); + ClassLoader classLoader; + ClassLoader systemClassLoader; + + try { + classLoader = getClassLoader(clazz); + } catch(SecurityException ex) { + // not much useful diagnostics we can print here! + logDiagnostic( + "Security forbids determining the classloader for " + className); + return; + } + + logDiagnostic( + "Class " + className + " was loaded via classloader " + + objectId(classLoader)); + + try { + systemClassLoader = ClassLoader.getSystemClassLoader(); + } catch(SecurityException ex) { + logDiagnostic( + "Security forbids determining the system classloader."); + return; + } + + if (classLoader != null) { + StringBuffer buf = new StringBuffer("ClassLoader tree:"); + for(;;) { + buf.append(objectId(classLoader)); + if (classLoader == systemClassLoader) { + buf.append(" (SYSTEM) "); + } + + try { + classLoader = classLoader.getParent(); + } catch(SecurityException ex) { + buf.append(" --> SECRET"); + break; + } + + buf.append(" --> "); + if (classLoader == null) { + buf.append("BOOT"); + break; + } + } + logDiagnostic(buf.toString()); + } + } + + /** + * Returns a string that uniquely identifies the specified object, including + * its class. + *
+ * The returned string is of form "classname@hashcode", ie is the same as + * the return value of the Object.toString() method, but works even when + * the specified object's class has overidden the toString method. + * + * @param o may be null. + * @return + */ + public static String objectId(Object o) { + if (o == null) { + return "null"; + } else { + return o.getClass().getName() + "@" + System.identityHashCode(o); + } + } + // ---------------------------------------------------------------------- // Static initialiser block to perform initialisation at class load time. // @@ -825,8 +1245,11 @@ public abstract class LogFactory { // ---------------------------------------------------------------------- static { + // note: it's safe to call methods before initInternalLogging.. thisClassLoader = getClassLoader(LogFactory.class); + initDiagnostics(); + logClassLoaderTree(LogFactory.class); factories = createFactoryStore(); - } + } }