Issue1327

In a system with the standalone jython 2.5b3 jar file contained in
tomcat's common/lib directory (so all web apps can see it) reloading
webapps using Tomcat's standard manager reload will fail if the python
code used by the servlet subclasses any classes defined in that servlet.

For example, in a servlet if you define the interface:

package org.me.myservlet;
public interface Pig
{
    public String oink();
}

and then invoke the following python script in that servlet (using, for
example, PythonInterpreter.execfile()):

from org.me.myservlet import Pig
class PyPig(Pig):
    def oink(self): return "oink"

And then start Tomcat, execute the script, reload the webapp and try to
execute the script again it will fail. The tomcat error is:

2009-04-24 10:10:36,234 INFO  [http-8080-Processor23]
loader.WebappClassLoader  - Illegal access: this web application
instance has been stopped already.  Could not load
org.python.core.PyProxy.  The eventual following stack trace is caused
by an error thrown for debugging purposes as well as to attempt to
terminate the thread which caused the illegal access, and has no
functional impact.
java.lang.IllegalStateException
	at
org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1272)
	at
org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1232)
	at org.python.core.BytecodeLoader$Loader.loadClass(BytecodeLoader.java:96)
	at java.lang.ClassLoader.loadClass(ClassLoader.java:252)
	at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:320)
	at java.lang.ClassLoader.defineClass1(Native Method)
	at java.lang.ClassLoader.defineClass(ClassLoader.java:621)
	at
org.python.core.BytecodeLoader$Loader.loadClassFromBytes(BytecodeLoader.java:116)
	at org.python.core.BytecodeLoader.makeClass(BytecodeLoader.java:35)
	at org.python.core.BytecodeLoader.makeClass(BytecodeLoader.java:50)
	at org.python.core.MakeProxies.makeClass(MakeProxies.java:29)
	at org.python.core.MakeProxies.makeProxy(MakeProxies.java:74)
	at org.python.core.PyType.newType(PyType.java:189)
	at org.python.core.PyType.type___new__(PyType.java:121)
	at org.python.core.PyType$exposed___new__.new_impl(Unknown Source)
	at org.python.core.PyType.invoke_new_(PyType.java:340)
	at org.python.core.PyType.type___call__(PyType.java:1200)
	at org.python.core.PyType.__call__(PyType.java:1191)
	at org.python.core.PyObject.__call__(PyObject.java:386)
	at org.python.core.Py.makeClass(Py.java:1587)
	at org.python.core.Py.makeClass(Py.java:1529)
	at org.python.core.Py.makeClass(Py.java:1517)
	at
org.python.pycode._pyx4.f$0(C:\code\dev\build\debug\server\extensions\installed\pytest\1.0\webapp\WEB-INF\test.py:12)
	at
org.python.pycode._pyx4.call_function(C:\code\dev\build\debug\server\extensions\installed\pytest\1.0\webapp\WEB-INF\test.py)
	at org.python.core.PyTableCode.call(PyTableCode.java:166)
	at org.python.core.PyCode.call(PyCode.java:14)
	at org.python.core.Py.runCode(Py.java:1206)
	at org.python.core.__builtin__.execfile_flags(__builtin__.java:538)
	at org.python.util.PythonInterpreter.execfile(PythonInterpreter.java:142)
	

I spent some time debugging this, and found that the second time you run
the script, the java objects for the java-defined interface (Pig) is the
_old_ one, from the old classloader. I strongly suspect there is some
static cache or map of java objects in the python code that needs to get
flushed on servlet reload. I am happy to make my code call an explicit
flush/cleanup function if one can be provided.

For example, I saw the static map PyType.class_to_type, which seems to
hold java objects yet provides no way to clean itself up. I am not sure
if this is the root cause of my problem or not, maybe some other static
cache is at fault. 

This will fail not only in Tomcat but in any other environment where
classloaders can come and go (e.g. OSGi)

CCing Colin as he experienced a similar issue

First of all ensure you're calling cleanup() in your Servlet's destroy 
method. If you're using a modjy servlet, it's not doing this in 2.5.1 
(but will in 2.5.2)

Though I'm not sure that will actually solve the problem -- I think the 
problem lies with our ThreadState objects not being cleaned up when the 
PythonInterpreter is destroyed. So we can end up with older recycled 
PySystemStates

I have been doing some more investigation here, using visualvm to find all the references to the classloader being leaked.

Philip, you are right about the thread-local PySystemState - I put try {} around my use of the python interpreter with Py.setSystemState(null) in the finally block, which seemed to help. 

As an aside, jython's use of thread-local storage for system state is really aggravating - I have run into bugs in the past where a python script calls into java which calls back into jython, and my system state has been clobbered - basically I now use the following pattern every time I run a script through a PythonInterpreter: save off the current state, run the script, and reset the state to the old value in a finally{} block. It would be *so* much nicer if jython could do this for me, or just not use TLS at all!

I found another place where classloaders were being leaked as well: PyFile's Closer class. Apparently a Closer object is registered with the JVM each time a PyFile is created and used. If the jython jar is in a servlet then this contains a reference to the servlet's classloader and thus the servlet's classes will never be cleaned up after the servlet is reloaded. Doesn't the JVM handle closing open file handles on exit (or doesn't the operating system handle that?) Why does this code exist? It seems to me that we could safely remove the Closers from PyFile and fix this memory leak. What do you think?

I am continuing to look at this, and will let you know if I find anything else....

woo hoo! After much debugging with visualvm and friends I have finally tracked down all of the sources of classloader leaks in jython, and after making a couple of changes to the jython source I successfully built a servlet that calls into the jython interpreter and whose classloader is garbage collected when the servlet is reloaded.

Here are the issues I found, along with the fixes I applied. If someone could apply changes along these lines to jython I would really appreciate it and I'd consider this bug closed:

(1) Use of thread-local storage: PySystemState objects are stored in TLS, and since my servlet has jython in its WEB-INF/lib directory, that means that all jython classes are loaded by the servlet's classloader. In Tomcat, threads are long-lived, so putting something in TLS causes it to hang around for a long time. Consequently, references to the servlet classloader remained in TLS long after the servlet was reloaded.

To fix this, I added a method to the Py class to explicitly clear out the PySystemState in thread-local storage. I am calling this in a finally block after my interpreter runs; it seems to me that it would be nice to add this call to PythonInterpreter.cleanup() so that cleanup() can be the one method that users call to fully cleanup.

Changes:
  (a) added the following to the class org.python.core.Py:

    public static void clearThreadLocalState()
    {
        threadStateMapping.remove();
    }

    (b) added the remove() method to org.python.core.ThreadStateMapping:

    public void remove()
    {
        cachedThreadState.remove();
    }

(2) PyFile's use of JVM shutdown hooks: PyFile adds a PyFileCloser instance to the JVM's list of shutdown hooks on line 584 of PyFile.java. This causes a classloader leak because the instance added has the Servlet's classloader, and the list of shutdown hooks is never cleared out until the JVM shuts down.

I do not think this is necessary - the JVM will close all open file handles when it exits, so this shutdown hook seems to serve no purpose. I fixed this by commenting out all references to the Closers and the shutdown hook.

After I made both of the changes above, my servlet began unloading correctly. As I said above, I really hope you apply these changes and close this bug so that I can start using an official build of jython (rather than my hacked up local copy!)

Matt,

Thanks for the great work on figuring out the underlying issues. In terms of your latest comment, applying #1 looks fine, and I will apply it soon (I'm camping right now, however).

Re #2, looking at Closer logic in PyFile, I think the issue here is that objects derived from PyFile can potentially have more interesting close logic defined, so we can't simply rely on JVM shutdown for an orderly close. However, we need to figure out a mechanism that doesn't prevent servlet unloading.

Jim: thanks for checking bug status while camping - that is impressive dedication! :)

Update: I found that my fix is not 100% sufficient - it turns out I cannot easily intercept all thread paths into the jython runtime - for example, I found the JVM the Finalizer thread, when calling finalize() on certain jython classes, can trigger thread-local storage to be created (e.g. in PyGenerator and PyFinalizableInstance) Also, I am afraid there could be other cases where python classes that subclass Java classes/interfaces are associated with other (pure) Java classes and thus jython code can be called without me having the ability to wrap it in a try/finally and clear out the thread-local storage.

So, I made a more substantial change to ThreadStateMapping that keeps track of everything added to TLS and includes a new "shutdown()" method that is meant to be called when the classloader is being destroyed (e.g. when tomcat is trying to reload a servlet). This code does indeed work, and I have verified that classloaders are garbage collected when I call this.

The code is a little less intuitive that my other changes - I can provide more rationale/explanation if need be.

------------------------------------------------------------------
ThreadStateMapping.java
------------------------------------------------------------------

package org.python.core;

import java.util.ArrayList;
import java.lang.ref.WeakReference;

class ThreadStateMapping {
    //private static final ThreadLocal<ThreadState> cachedThreadState = new ThreadLocal<ThreadState>();
    private static final ThreadLocal<Object[]> cachedThreadState =
            new ThreadLocal<Object[]>()
            {
                @Override
                protected Object[] initialValue()
                {
                    return new Object[1];
                }
            };

    private ArrayList<WeakReference<Object[]>> threadStateList = new ArrayList<WeakReference<Object[]>>();
    private boolean isShutdown = false;

    public ThreadState getThreadState(PySystemState newSystemState) {

        //initial check for usual case outside syncronized block for efficiency
        ThreadState ts = (ThreadState)cachedThreadState.get()[0];

        if (ts != null) {
            return ts;
        }

        synchronized(this)
        {
            //check again within synchronized block to guard against race condition
            Object[] threadLocal = cachedThreadState.get();
            if(threadLocal[0] != null)
                return (ThreadState)threadLocal[0];

            Thread t = Thread.currentThread();
            if (newSystemState == null) {
                Py.writeDebug("threadstate", "no current system state");
                if (Py.defaultSystemState == null) {
                    PySystemState.initialize();
                }
                newSystemState = Py.defaultSystemState;
            }

            ts = new ThreadState(t, newSystemState);

            if(! isShutdown)
            {
                threadLocal[0] = ts;
                threadStateList.add(new WeakReference<Object[]>(threadLocal));
            }
            return ts;
        }
    }


    public synchronized void shutdown()
    {
        isShutdown = true;
        for(WeakReference<Object[]> ref : threadStateList)
        {
            Object[] o = ref.get();
            if(o != null)
            {
                o[0] = null;
            }
        }
        threadStateList.clear();
    }
}

------------------------------------------------------------------
A slightly different method name in Py.java:
------------------------------------------------------------------
    public static void clearAllThreadLocalState()
    {
        threadStateMapping.shutdown();
    }

Matt,

Two things:

1. Can you provide a patch file of your changes and attach? It's much easier to evaluate and apply without inadvertent bugs being introduced. It's also trivial:

svn diff > issue1327.patch

(You can also control which files are diffed if you have other stuff changed.)

2. For Closers, I think we should register them with the PySystemState; this represents the overall global state and it's CPython's execution model too. We should do the same with the ThreadStateMapping so the shutdown is done with respect to PySystemState. (Such states can be shared by interpreters, but as clear in the use of PythonInterpreter#cleanup, only with care!) One of the biggest issues with Jython internals now is too much unnecessary globality, perhaps because it was more efficient on earlier JVMs. Regardless we don't want to introduce more now.

However, we may want some convenience methods to get at all of these states/interpreters and do things like shut them all down (but only maintain weakrefs! we don't want to move the problem). 

[This week I'm camping in Lake Dillon, which means far better connectivity than last week in Aspen/Crested Butte!]

OK, I uploaded the patch files that correspond to the code I pasted into the comments yesterday.

Re. Closers in PySystemState - sounds good to me! I agree that moving away from global state is a very good thing, and if it is moved out of the JVM shutdown hook, that will fix the classloader leak as well.

Here are a few comments on the changes I made. Hopefully this will shed some light on why I coded things the way I did.

The fundamental problem is that classes from the jython jar file are contained in thread-local storage. This is what causes the classloader leak when a servlet hosting the jython jar file is reloaded (because tomcat and most other app servers use thread pools, so the threads in the pools contain references to classes in the old classloader.)

What I would *love* to see is a move away from using TLS at all, but barring that, there are two ways to clean up thread local storage on shutdown: 
  (1) Iterate all the threads and access the private member variable that holds the thread locals. Sample code that does this can be found here: http://blog.igorminar.com/2009/03/identifying-threadlocal-memory-leaks-in.html and here: http://weblogs.java.net/blog/jjviana/archive/2010/06/09/dealing-glassfish-301-memory-leak-or-threadlocal-thread-pool-bad-ide . I rejected this approach because it (a) ties you to a specific JRE implementation and (b) requires the JVM be running with certain security setting to allow exposing private member variables.
  (2) Don't store our classes in TLS - this is the approach I took. Rather than store org.python.core.ThreadState objects directly in TLS, I store Object[1] instances. I put the ThreadState object into the first element in this array. I also keep track of all the arrays I have put in TLS using weak references in the array "threadStateList". When it comes time to cleanup, I simply iterate this list, nulling out the first element of each array. Thus, each thread still has a TLS variable, but it is an object array with null in it, so there are no references to any org.python.* classes.

The boolean "isShutdown" prevents stuff from getting added back to TLS after we have cleaned up. For example, I have found that the finalizer thread can add python thread locals (see my other post) 

Because I introduced some global state (threadStateList and isShutdown), I also had to add some synchronization to this class. However, I didn't want to make the usual case (get from TLS after it has been set) to be slower. That is why the initial check for TLS at the beginning of getThreadState() is not synchronized - the synchronized block comes after that check. In this way, most calls to this method should be as fast as they were before.

I think that should explain everything - let me know if there are any other questions/concerns.

Closers and ThreadStateMapping need to be fixed so that classloaders can GC prior to 2.5.2 beta 2.

I've been thinking about this issue for a while, specifically the patch by Matt on July 7. The explicit clearing of all ThreadStates seems to me to be too drastic.

What I think we should do instead is associate a set of ThreadStstes with a given PySystemState (I don't believe one could share a TS across a PySystemState, and it certainly would not be advised.) When that PySystemState is being cleared, all the ThreadStates can then be released. This is also the appropriate time to run any Closer on opened files associated with the PySystemState. There may be other cleanup.

Any thoughts?

Lastly, I marked this issue urgent a couple of days ago because it's a bug that must be closed before we can do a 2.5.2 beta 2, given that it's a resource leak (especially given the type of apps this impacts).

I have committed a patch as of r7109 which I believe fixes this problem of a chain of hard refs to classes in the classloaders. It builds upon the patch that Matt submitted, but centralizes the resource registration (and any closing) with PySystemState through a new class, PySystemStateCloser.

In addition, it uses Guava's FinalizableReferenceQueue, which is specifically engineered to not have classloader leaks, to close these resources. Ordinarily then one shouldn't have to manually do a cleanup of PySystemState. I didn't want to change the API here of using PySystemState for most usage. Given that its just permgen exhaustion we are concerned about, GC cleanup should suffice.

So now we need to test this, especially to verify there are no more chains that need to be broken. However, I believe the process in place now is general enough so that can be readily done.

Any feedback on this bug? I would like to close this ASAP so we can get out beta 2 :)

Jim,

I will check out this change and provide feedback in a day or so. Thanks a lot for making the fix!

quick update - tried jython with these changes & updated my code to call PySystemState.shutdown() to cleanup, but I am getting a classloader leak. I'm debugging it now - will let you know when I've determined the root cause.

Ideally no call to #shutdown is necessary, but it does require testing by forcing GC perhaps a number of times.

Spent a little more time looking at the heap dump and here are some places that I think are pinning the classloader:
 (1) ShutdownCloser (nested class PySystemState$PySystemStateCloser$ShutdownCloser) is registered as a shutdown hook, which as I pointed out previously, will pin the classloader.
 (2) Some elements of the com.google.common.base.internal.Finalizer thread appear to reference the containing classloader (contextClassLoader and inheritedAccessControlContext member variables) - bug #92 in guava (http://code.google.com/p/guava-libraries/issues/detail?id=92) mentions this as well (see comment #6). Apparently this was discovered in 2008 but still not fixed. 

There are a whole bunch more references to the finalizer thread, but I am hoping that those will go away once the other references to the webapp classloader are cleared.

Matt, would it be possible for you to submit the smallest test case that reproduces this problem? This would obviously be very useful for us to converge on fixing this problem. Ideally it would be a JUnit test; see some examples in tests/java/org/python/tests/ in trunk.

Axis2 had a similar issue with shutdown hook registration preventing classloader unloading, https://issues.apache.org/jira/browse/AXIS2-3861

From what I gather there and the companion issue, removeShutdownHook should suffice. I will make that change.

I committed another variation on this in r7112, based on Matt's feedback. This deregisters the shutdown hook and uses a passive cleanup strategy similar to what is done in PyType instead of using Guava's FinalizableReferenceQueue.

I will do a svn update and try out the new change.

I can get a minimal test case in a bit, but in summary I test in the following way: I have created a minimal web app (servlet) that just opens and runs a python script using the jython library as a part of its initialization. I install this in Tomcat, start Tomcat, and then use the Tomcat manager to remove my test web app. Finally, I verify the classloader was GCed by forcing some JVM GCs and then doing a heap dump with a tool like VisualVM or yourkit.

Ideally we can create a test case that doesn't require Tomcat or manual
intervention.

following way: I have created a minimal web app (servlet) that just opens
and runs a python script using the jython library as a part of its
initialization. I install this in Tomcat, start Tomcat, and then use the
Tomcat manager to remove my test web app. Finally, I verify the classloader
was GCed by forcing some JVM GCs and then doing a heap dump with a tool like
VisualVM or yourkit.
>
> _______________________________________
> Jython tracker <report@bugs.jython.org>
> <http://bugs.jython.org/issue1327>
> _______________________________________

My code started breaking under the following conditions:
- Deriving a Python class from a Java interface
- Getting a reference to self in __init__ and:
   - passing self as a parameter to a Java method

Code along the lines of the following will hit this bug:

class MyRunnable (Runnable):
   def __init__(self,x):
      self._x = x
      SwingUtilities.invokeLater( self )



Some debugging led me to the conclusion that it was because the java proxy was not initialised properly.

PyObject#proxyInit was being called.

This lead through some compiled Python class files to invoking Py#initProxy

Where:
the call to ThreadState#getInitializingProxy() returned null.

This was due to the fact that the ThreadState objects were being lost.

This seems to be because ThreadStateMapping#getThreadState determines that there is no cached thread state.
So it creates a new one.
But it does not place it into the single element array in the cache, before returning it.
Resulting in a new ThreadState being returned each time.

The attached patch attempts to address this issue.

Geoffrey, I think the issue here is that we have a bad implementation of double-checked locking. The aspect of how it interacts with thread locals makes it subtle, so I'm going to make the whole lookup synchronized.

In general, we usually pass the ThreadState in our code, but this could be a performance bottleneck especially at callbacks from Java. Let's worry about that later, correctness first.

Removal of double checked locking in r7117.

Going forward, we should reconsider the use of ThreadLocal to manage
the ThreadState mapping. Synchronizing this loses any performance from
using ThreadLocal, but we have to deal with the other issues seen
here. Also, I think we should expose the registration process more, in
the case of usage with thread pools.

It might make sense to switch to the use of Guava's support for computed maps to support this.

Backed out changes in r7120 related to registering and then nulling ThreadState in the ThreadStateMapping, since there are too many problems with it, including backwards breaking API changes.

We need to rethink our management of ThreadState, but this will be in the larger context of the PySystemState refactoring that we plan to do in Jython 2.6.

Fortunately there's a workaround for cleaning ThreadLocal managed objects like this, see http://weblogs.java.net/blog/jjviana/archive/2010/06/09/dealing-glassfish-301-memory-leak-or-threadlocal-thread-pool-bad-ide

Marking as "normal" to indicate it is no longer a blocker for 2.5.2. Deferring remaining work to 2.6.

I have added a patch to demonstrate how we can remove the linked list maintained by initializingProxies and instead just use a simpler mechanism of managing it in the stack (but linkage via a ThreadLocal). This could be part of a more general refactoring of ThreadState, to separate reentrancy management from state mgmt.

Bob Lee's blog post on ThreadLocal is pretty useful for understanding this simplification:
http://blog.crazybob.org/2006/07/hard-core-java-threadlocal.html

We can apply something similar to other reentrancy state, such as enterRepr/exitRepr, compareStateDict, and recursion_depth.

Any actual change should just integrate this into ThreadState, instead of yet another auxiliary class (ThreadContext here). (Although in this case, it has no impact because proxy init always must use a ThreadLocal because it's going from Python -> Java -> Python.)

The introduction of google guava seems to add one more cause for a class loader leak: I'm seeing a daemon thread "org.python.google.common.base.internal.Finalizer" which doesn't exit after releasing the jython interpreter. It keeps the classloader indirectly in the thread's inherited AccessControlContext. Seems to be a known guava issue:
http://code.google.com/p/guava-libraries/issues/detail?id=92

Sebastian Eifert, thanks for pointing out http://code.google.com/p/guava-libraries/issues/detail?id=92, looks like this will be fixed in guava-12 - 2.7 is currently using guava-11.0.2. I will ensure this is updated in extlibs when it becomes available.

Re 2.7 dev, I'm going to start applying the ThreadState refactoring I suggested from about 18 months ago, given that the small backwards breaking API concerns for 2.5.x do not matter for 2.7.

Guava 12.0 has since been released.  I've tested it, and, so far, it seems to have fixed the ThreadLocal leaks I had been seeing originating from Guava.  Of course, others are unaffected.

Note: Guava 12.0 requires Java 6 or later, so jython 2.5 seems ineligible for this update.

Jeffrey Knockel: thanks for the update! Jython 2.6 also requires JDK6 so the update should be fine.

Jim: any chance of this making it in soon?

I'm going to look this over and most likely apply it to 2.7 before I roll a beta. Hopefully this will be soon.

Jim: is threadstate.patch the final attempt? And do you have advice for testing it?

Feels good to close multi-year epic issues like this. Jim Baker's patch is in and Guava dependency is updated for 2.7.