Uploaded image for project: 'Commons Logging'
  1. Commons Logging
  2. LOGGING-34

[logging] ContextClassLoader may load Log impl from wrong context in JDK 1.4

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Cannot Reproduce
    • Affects Version/s: 1.0.3
    • Fix Version/s: None
    • Labels:
      None
    • Environment:

      Operating System: other
      Platform: All

    • Bugzilla Id:
      28291

      Description

      The static method org.apache.commons.logging.LogFactory#getContextClassLoader
      will return the ClassLoader for the currently executing thread
      Thread.currentThread(). If this ClassLoader is different from the ClassLoader
      which loaded org.apache.commons.logging.Log, the implementing class cannot be
      cast to Log.

      This results in Log.class.isAssignableFrom(logClass) returning false even
      though logClass implements Log. In turn, this causes
      org.apache.commons.logging.impl.LogFactoryImpl#getLogConstructor() to
      incorrectly throw the exception "Class " + logClass + " does not implement Log"

      The solution is to use the same ClassLoader that was used to load
      org.apache.commons.logging.Log.

      On line 463 of LogFactoryImpl.java, replace the line:
      ClassLoader threadCL = getContextClassLoader();

      with:
      ClassLoader threadCL = Log.class.getClassLoader();

      The only was I am aware of to reproduce this bug is to write a Jakarta Cactus
      Test Suite and run the test using junit.swingui.TestRunner.main or
      junit.awtui.TestRunner.main. Because the Thread has a different
      ContextClassLoader, commons-logging will fail to instantiate the Log
      implementation.

        Activity

        Hide
        skitching Simon Kitching added a comment -

        (In reply to comment #12)
        > Catalin, how exactly are you undeploying your webapp?
        And how exactly are you measuring the memory leak?

        Show
        skitching Simon Kitching added a comment - (In reply to comment #12) > Catalin, how exactly are you undeploying your webapp? And how exactly are you measuring the memory leak?
        Hide
        skitching Simon Kitching added a comment -

        (In reply to comment #11)
        > When running on Tomcat, the container should call release
        > on the instance loaded in the shared library after each
        > classloader is deployed. This is why I made this suggestion.

        Ah. So Tomcat has an ugly hack to specifically work around this issue with
        commons-logging. Yep, I see it in
        org.apache.catalina.loader.WebappClassLoader#stop:

        public void stop() throws LifecycleException {
        ....
        org.apache.commons.logging.LogFactory.release(this);

        Because this hack exists, the bug I described doesn't occur in Tomcat, ie when
        commons-logging.jar is deployed via the shared classloader, memory is correctly
        released on undeploy.

        Note that the real bug exists in commons-logging. A container shouldn't need
        to call o.a.c.l.LogFactory.release (and most won't). Tomcat is trying to be nice
        to webapps that use commons-logging, and in one sense the call doesn't do any
        harm. However doing this does make porting to another servlet container
        interesting, when a leak suddenly appears..) - and confuses people like me who
        know commons-logging and are confused when it doesn't leak as expected .

        A completely portable solution (I think) would be for the deployed app to
        register for a callback on undeploy and have the app call LogFactory.release
        itself. Class ServletContextListener provides a method contextDestroyed that
        should be able to do this (http://java.sun.com/j2ee/sdk_1.3/techdocs/api/) for
        any servlet engine that supports java servlet 2.3. Note that I haven't tried
        this myself though.

        Just as a matter of style, I wouldn't recommend deploying libs in a "shared"
        manner (ie visible to all webapps). This may provide a minor performance
        benefit, or reduce memory consumption, but in my view it is just plain ugly, on
        the same order as making class member variables public instead of providing
        getter and setter methods, just to improve performance. But that's only my
        personal opinion, and I know many people disagree.

        If LogFactory.release is going to be called on unload, then this should work
        fine regardless of whether the LogFactory class was loaded via the shared
        classloader (shared/lib) or via the component-specific classloader (WEB-INF/lib).

        However Catalin was getting a leak when commons-logging.jar was deployed in
        WEB-INF/lib. I wonder why (my previous argument no longer applies, as Tomcat
        is calling LogFactory.release on undeploy).

        Catalin, how exactly are you undeploying your webapp?

        Show
        skitching Simon Kitching added a comment - (In reply to comment #11) > When running on Tomcat, the container should call release > on the instance loaded in the shared library after each > classloader is deployed. This is why I made this suggestion. Ah. So Tomcat has an ugly hack to specifically work around this issue with commons-logging. Yep, I see it in org.apache.catalina.loader.WebappClassLoader#stop: public void stop() throws LifecycleException { .... org.apache.commons.logging.LogFactory.release(this); Because this hack exists, the bug I described doesn't occur in Tomcat, ie when commons-logging.jar is deployed via the shared classloader, memory is correctly released on undeploy. Note that the real bug exists in commons-logging. A container shouldn't need to call o.a.c.l.LogFactory.release (and most won't). Tomcat is trying to be nice to webapps that use commons-logging, and in one sense the call doesn't do any harm . However doing this does make porting to another servlet container interesting, when a leak suddenly appears..) - and confuses people like me who know commons-logging and are confused when it doesn't leak as expected . A completely portable solution (I think) would be for the deployed app to register for a callback on undeploy and have the app call LogFactory.release itself. Class ServletContextListener provides a method contextDestroyed that should be able to do this ( http://java.sun.com/j2ee/sdk_1.3/techdocs/api/ ) for any servlet engine that supports java servlet 2.3. Note that I haven't tried this myself though. Just as a matter of style, I wouldn't recommend deploying libs in a "shared" manner (ie visible to all webapps). This may provide a minor performance benefit, or reduce memory consumption, but in my view it is just plain ugly, on the same order as making class member variables public instead of providing getter and setter methods, just to improve performance. But that's only my personal opinion, and I know many people disagree. If LogFactory.release is going to be called on unload, then this should work fine regardless of whether the LogFactory class was loaded via the shared classloader (shared/lib) or via the component-specific classloader (WEB-INF/lib). However Catalin was getting a leak when commons-logging.jar was deployed in WEB-INF/lib. I wonder why (my previous argument no longer applies, as Tomcat is calling LogFactory.release on undeploy). Catalin, how exactly are you undeploying your webapp?
        Hide
        rdonkin@apache.org rdonkin@apache.org added a comment -

        When running on Tomcat, the container should call release on the instance loaded
        in the shared library after each classloader is deployed. This is why I made
        this suggestion.

        It's hard to know whether the classloader will get collected upon hot deployment
        even when LogFactory is defined by the child classloader on all platforms (which
        is why I caveated my answers). Garbage collection and reflection has had some
        wrinkles (and bugs). I wouldn't be surprised if it didn't on some (but would
        bet on it).

        The way that I would have proceeded would have been to set a hot deployment test
        for my particular application to determine whether there is a detectable memory
        leak. (I believe that this is how the tomcat problems were first recognized.)
        However, Chris asked for a therotical answer so I did my best.

        Show
        rdonkin@apache.org rdonkin@apache.org added a comment - When running on Tomcat, the container should call release on the instance loaded in the shared library after each classloader is deployed. This is why I made this suggestion. It's hard to know whether the classloader will get collected upon hot deployment even when LogFactory is defined by the child classloader on all platforms (which is why I caveated my answers). Garbage collection and reflection has had some wrinkles (and bugs). I wouldn't be surprised if it didn't on some (but would bet on it). The way that I would have proceeded would have been to set a hot deployment test for my particular application to determine whether there is a detectable memory leak. (I believe that this is how the tomcat problems were first recognized.) However, Chris asked for a therotical answer so I did my best.
        Hide
        skitching Simon Kitching added a comment -

        Robert, why would you think that putting commons-logging.jar in shared/lib would
        resolve the issue?

        The problem is caused by Hashtable LogFactory.factories having an entry whose
        key is a classloader that has been "undeployed". Shouldn't the solution be to
        ensure that LogFactory gets loaded by the component classloader, not the
        shared classloader, so that when the container "forgets" the component
        classloader there are no longer any references to it (apart from circular ones
        that the garbage collector can handle)?

        NB: we're talking about JCL-1.0.4 here (no weak references).

        Show
        skitching Simon Kitching added a comment - Robert, why would you think that putting commons-logging.jar in shared/lib would resolve the issue? The problem is caused by Hashtable LogFactory.factories having an entry whose key is a classloader that has been "undeployed". Shouldn't the solution be to ensure that LogFactory gets loaded by the component classloader, not the shared classloader, so that when the container "forgets" the component classloader there are no longer any references to it (apart from circular ones that the garbage collector can handle)? NB: we're talking about JCL-1.0.4 here (no weak references).
        Hide
        rdonkin@apache.org rdonkin@apache.org added a comment -

        It's hard to be categorical since there are variations between JVMs. There are known circumstances
        where 1.0.4 holds references to classloaders in some containers (but not tomcat) preventing recycling
        of memory in undeployment. It would not surprise me to find that this is one of those circumstances (at
        least on some platforms).

        If this is a concern, there are a number of actions you might take (any of which should be effective):

        1 If you are going to be hot deploying applications frequently and deploying your logging systems in
        the child classloader for the web application, then it is a very good idea to add a lifecycle listener to
        ensure that all logging resources are correctly closed. If you are logging to Log4J, you should be doing
        this anyway. If you are concerned about releasing references then you should call JCL release during
        this cleanup.

        2 Download the new JCL alpha and install the optional jar. The weak references should allow the
        memory to be recycled (sooner or later).

        3 Reconsider your deployment decision. I'm not sure why you are unhappy to deploy your logging
        system in share/lib. Logging systems tend to hold a number of resources open for performance
        reasons. Hot deployment therefore isn't particularly pretty for them. There are sometimes good reasons
        why people are forced to deploy all libraries in the application loader (perhaps because they do not
        control the container). In other cases, it's worth considering the best deployment strategy.

        Show
        rdonkin@apache.org rdonkin@apache.org added a comment - It's hard to be categorical since there are variations between JVMs. There are known circumstances where 1.0.4 holds references to classloaders in some containers (but not tomcat) preventing recycling of memory in undeployment. It would not surprise me to find that this is one of those circumstances (at least on some platforms). If this is a concern, there are a number of actions you might take (any of which should be effective): 1 If you are going to be hot deploying applications frequently and deploying your logging systems in the child classloader for the web application, then it is a very good idea to add a lifecycle listener to ensure that all logging resources are correctly closed. If you are logging to Log4J, you should be doing this anyway. If you are concerned about releasing references then you should call JCL release during this cleanup. 2 Download the new JCL alpha and install the optional jar. The weak references should allow the memory to be recycled (sooner or later). 3 Reconsider your deployment decision. I'm not sure why you are unhappy to deploy your logging system in share/lib. Logging systems tend to hold a number of resources open for performance reasons. Hot deployment therefore isn't particularly pretty for them. There are sometimes good reasons why people are forced to deploy all libraries in the application loader (perhaps because they do not control the container). In other cases, it's worth considering the best deployment strategy.
        Hide
        catalin Catalin Grigoroscuta added a comment -

        (In reply to comment #7)
        >
        > If the "thread context classloader" is adhering to the "parent first" search
        > behavior, then this would only be a problem if the "thread context
        > classloader" did not have the "current class's classloader" in it's hierarchy.
        >
        I would like to reopen the discussion from this point.

        The behaviour described above can actually lead (and actually did) to a
        significant memory leak in the following circumstance: I deploy a web
        application in Tomcat. The application uses log4j to log, and has
        commons-logging.jar and log4j.jar in WEB-INF/lib. Tomcat also uses common-loggings.
        The problem is that I find myslef in the situation where tomcat classes get to
        use a Log instance loaded by the class loader of my web application (which is,
        of course, the context class loader during the execution of servlets). This will
        prevent the web app from being garbage collected when I stop it.

        The only workaroung for this was to put common-logging.jar and log4j.jar in
        share/lib instead of WEB-INF/lib, but I'm not really happy with this solution.

        Could somebody confirm this problem?
        The guys from Tomcat do not admit this is a bug for them, but I belive this
        actually affects Tomcat.

        Show
        catalin Catalin Grigoroscuta added a comment - (In reply to comment #7) > > If the "thread context classloader" is adhering to the "parent first" search > behavior, then this would only be a problem if the "thread context > classloader" did not have the "current class's classloader" in it's hierarchy. > I would like to reopen the discussion from this point. The behaviour described above can actually lead (and actually did) to a significant memory leak in the following circumstance: I deploy a web application in Tomcat. The application uses log4j to log, and has commons-logging.jar and log4j.jar in WEB-INF/lib. Tomcat also uses common-loggings. The problem is that I find myslef in the situation where tomcat classes get to use a Log instance loaded by the class loader of my web application (which is, of course, the context class loader during the execution of servlets). This will prevent the web app from being garbage collected when I stop it. The only workaroung for this was to put common-logging.jar and log4j.jar in share/lib instead of WEB-INF/lib, but I'm not really happy with this solution. Could somebody confirm this problem? The guys from Tomcat do not admit this is a bug for them, but I belive this actually affects Tomcat.
        Hide
        rsitze@apache.org Richard A. Sitze added a comment -

        Either point will break JCL. My assumption is irrelevant in the end.

        I'm simply asking the defect owner to help identify which one might be
        working here.

        If the "thread context classloader" is adhering to the "parent first" search
        behavior, then this would only be a problem if the "thread context
        classloader" did not have the "current class's classloader" in it's hierarchy.

        If the "thread context classloader" is adhering to the "child first" search
        behavior, then it opens up all sorts of ugly doors in a test environment, so
        I'm guessing this isn't true.

        Show
        rsitze@apache.org Richard A. Sitze added a comment - Either point will break JCL. My assumption is irrelevant in the end. I'm simply asking the defect owner to help identify which one might be working here. If the "thread context classloader" is adhering to the "parent first" search behavior, then this would only be a problem if the "thread context classloader" did not have the "current class's classloader" in it's hierarchy. If the "thread context classloader" is adhering to the "child first" search behavior, then it opens up all sorts of ugly doors in a test environment, so I'm guessing this isn't true.
        Hide
        ceki@apache.org Ceki Gulcu added a comment -

        I thought you had made a simple typo, hence my question "you mean point (2)?".
        Otherwise, the follwing two paragraphs do not make sense (to me).

        The discovery mechanism for commons-logging currently overlooks/assumes two points:
        1. That the thread-context class loader is a child who's parent hierarchy
        includes the commons-logging.jar.
        2. That the ClassLoaders in the current hierarchy exhibit the default
        parent-first behavior.

        Correction... my guess is that JUnit/Cactus are in conflict with point (1).
        That a thread context classloader is being set up that does not defer up a
        hierarchy that includes the commons logging code.

        I think in the second paragraph you meant to say:

        Correction... my guess is that JUnit/Cactus are in conflict with point (2).

        Show
        ceki@apache.org Ceki Gulcu added a comment - I thought you had made a simple typo, hence my question "you mean point (2)?". Otherwise, the follwing two paragraphs do not make sense (to me). The discovery mechanism for commons-logging currently overlooks/assumes two points: 1. That the thread-context class loader is a child who's parent hierarchy includes the commons-logging.jar. 2. That the ClassLoaders in the current hierarchy exhibit the default parent-first behavior. Correction... my guess is that JUnit/Cactus are in conflict with point (1). That a thread context classloader is being set up that does not defer up a hierarchy that includes the commons logging code. I think in the second paragraph you meant to say: Correction... my guess is that JUnit/Cactus are in conflict with point (2).
        Hide
        rsitze@apache.org Richard A. Sitze added a comment -

        I believe that in this particular case it is point (1), based on his
        description of the problem. I'm looking for confirmation.

        Point (2) would also create a problem, and I think that is more closely
        related to the errors you have been exposed to in the past.

        I'm writing a separate summary of both of these... to be posted shortly.

        Show
        rsitze@apache.org Richard A. Sitze added a comment - I believe that in this particular case it is point (1), based on his description of the problem. I'm looking for confirmation. Point (2) would also create a problem, and I think that is more closely related to the errors you have been exposed to in the past. I'm writing a separate summary of both of these... to be posted shortly.
        Hide
        ceki@apache.org Ceki Gulcu added a comment -

        Richard,

        You mean point (2)?

        Show
        ceki@apache.org Ceki Gulcu added a comment - Richard, You mean point (2)?
        Hide
        rsitze@apache.org Richard A. Sitze added a comment -

        Correction... my guess is that JUnit/Cactus are in conflict with point (1).
        That a thread context classloader is being set up that does not defer up a
        hierarchy that includes the commons logging code.

        Show
        rsitze@apache.org Richard A. Sitze added a comment - Correction... my guess is that JUnit/Cactus are in conflict with point (1). That a thread context classloader is being set up that does not defer up a hierarchy that includes the commons logging code.
        Hide
        rsitze@apache.org Richard A. Sitze added a comment -

        The opening statement is not necessarily true:

        "... If this ClassLoader [Thread.currentThread()] is different from the
        ClassLoader which loaded org.apache.commons.logging.Log, the implementing class
        cannot be cast to Log."

        Specifically, with the [default or expected] ClassLoader rule of deferring to
        the parent ClassLoader first, the implementing class will extend the Log class
        defined by the parent, and hence it can be cast.

        The discovery mechanism for commons-logging currently overlooks/assumes two points:
        1. That the thread-context class loader is a child who's parent hierarchy
        includes the commons-logging.jar.
        2. That the ClassLoaders in the current hierarchy exhibit the default
        parent-first behavior.

        I'm guessing it is this later scenario that some combination of JUnit/Cactus is
        doing.

        Would you help confirm this analysis of your problem?

        Show
        rsitze@apache.org Richard A. Sitze added a comment - The opening statement is not necessarily true: "... If this ClassLoader [Thread.currentThread()] is different from the ClassLoader which loaded org.apache.commons.logging.Log, the implementing class cannot be cast to Log." Specifically, with the [default or expected] ClassLoader rule of deferring to the parent ClassLoader first, the implementing class will extend the Log class defined by the parent, and hence it can be cast. The discovery mechanism for commons-logging currently overlooks/assumes two points: 1. That the thread-context class loader is a child who's parent hierarchy includes the commons-logging.jar. 2. That the ClassLoaders in the current hierarchy exhibit the default parent-first behavior. I'm guessing it is this later scenario that some combination of JUnit/Cactus is doing. Would you help confirm this analysis of your problem?
        Hide
        rdonkin@apache.org rdonkin@apache.org added a comment -

        Using the context classloader is vital if this code is going to run correctly in containers. So the
        proposed solution is probably a non-starter. Maybe I can think of an alternative solution...

        Show
        rdonkin@apache.org rdonkin@apache.org added a comment - Using the context classloader is vital if this code is going to run correctly in containers. So the proposed solution is probably a non-starter. Maybe I can think of an alternative solution...

          People

          • Assignee:
            Unassigned
            Reporter:
            chriseldredge@comcast.net Chris Eldredge
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development