[JAVA-130] Memory Leaks with ThreadLocals in Tomcat Created: 09/Jul/10 Updated: 09/Nov/10 Resolved: 30/Sep/10 |
|
| Status: | Closed |
| Project: | Java Driver |
| Component/s: | None |
| Affects Version/s: | 2.0 |
| Fix Version/s: | 2.2 |
| Type: | Bug | Priority: | Major - P3 |
| Reporter: | Klaus Lehner | Assignee: | Eliot Horowitz (Inactive) |
| Resolution: | Done | Votes: | 4 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Environment: |
Fedora, Tomcat |
||
| Attachments: |
|
| Description |
|
When running mongo 2.0 in a tomcat environment I can see the following logs in the catalina.out, and the tomcat web server can't be stopped any more without killing it, it seems that there's a non-deamon thread still hanging. SEVERE: A web application created a ThreadLocal with key of type [null] (value [com.mongodb.DBTCPConnector$1@d5ba1ef]) and a value of type [com.mongodb.DBTCPConnector.MyPort] (value [com.mongodb.DBTCPConnector$MyPort@7ae458c2]) but failed to remove it when the web application was stopped. To prevent a memory leak, the ThreadLocal has been forcibly removed. |
| Comments |
| Comment by Klaus Lehner [ 09/Nov/10 ] |
|
ah sorry - forgot to call close() as mentioned by eliot; will give that a try |
| Comment by Eliot Horowitz (Inactive) [ 09/Nov/10 ] |
|
Can you create a new case with the full log and steps to reproduce exactly? |
| Comment by Klaus Lehner [ 09/Nov/10 ] |
|
This is still the case, even with 2.3. I still have errors like that in my catalina.out and tomcat can't be stopped without killing it. Please reopen that task. SEVERE: A web application created a ThreadLocal with key of type [null] (value [com.mongodb.DBTCPConnector$1@4b6eb12]) and a value of type [com.mongodb.DBTCPConnector.MyPort] (value [com.mongodb.DBTCPConnector$MyPort@6fe23ecd]) but failed to remove it when the web application was stopped. To prevent a memory leak, the ThreadLocal has been forcibly removed. |
| Comment by Eliot Horowitz (Inactive) [ 11/Oct/10 ] |
|
The 2 in org.bson should never be using by normal operations, and accoring to tomcat docs, it seems the other should be. |
| Comment by Daniel Spilker [ 11/Oct/10 ] |
|
I tried the 2.2 driver today. Unfortunately this issue seems not to be fixed. I still count 3 thread locals (2 in org.bson.BSON and 1 in com.mongodb.DBTCPConnector). I do not see why these should get GC'ed when Mongo.close() is called, since the contents of the thread locals will still be referenced from each thread which used these classes. It will get GC'ed when the threads die, but in a shared environment like servlet containers where threads are pooled and reused this is not going to happen. |
| Comment by Robert Stewart [ 09/Oct/10 ] |
|
At first, I was still seeing one message being logged at SEVERE level. Tomcat, at least in version 6.0.24, seemed to be taking things into its own hands, though. Oct 8, 2010 11:08:19 PM org.apache.catalina.loader.WebappClassLoader clearThreadLocalMap This happens when I undeploy a webapp on Tomcat 6.0.24. The last sentence in the message is different than in previous comments posted on this issue. I think this is due to changes in more recent versions of Tomcat 6.0.x. In my webapp, I'm using my log4mongo-java appender for Log4J to log events to MongoDB. I've registered a ServletContextListener in my webapp that is called when the context is destroyed (e.g., when undeploying a webapp or shutting down Tomcat). In the callback, I Log4J's LogManager.close(), which eventually calls the close method on my appender, which finally calls Mongo.close(). After I patched mongo-java-driver with the fix I identified in http://jira.mongodb.org/browse/JAVA-180 (an NPE was preventing final clean up from occurring), the ThreadLocal was cleaned up and no messages were logged at SEVERE level. So, the 2.2 driver fixes the problems I was seeing with 2.1. |
| Comment by Eliot Horowitz (Inactive) [ 30/Sep/10 ] |
|
If you call Mongo.close() on application quit, everything should be cleaned up now. |
| Comment by auto [ 30/Sep/10 ] |
|
Author: {'login': 'erh', 'name': 'Eliot Horowitz', 'email': 'eliot@10gen.com'}Message: don't put OutMessage in ThreadLocal. |
| Comment by auto [ 30/Sep/10 ] |
|
Author: {'login': 'erh', 'name': 'Eliot Horowitz', 'email': 'eliot@10gen.com'}Message: doing our own UTF-8 Encoding so we can avoid extra buffers. this makes BSONEncoder lightweight |
| Comment by auto [ 30/Sep/10 ] |
|
Author: {'login': 'erh', 'name': 'Eliot Horowitz', 'email': 'eliot@10gen.com'}Message: remove 1 ThreadLocal by putting BSONDecoder in DBPort |
| Comment by Hans Meiser [ 22/Sep/10 ] |
|
Patch to move BSONDecoder into DBPort and remove threadlocal in Response. BSONDecoder is now per connection. |
| Comment by Eliot Horowitz (Inactive) [ 31/Aug/10 ] |
|
Still trying to figure out exactly what the bug or standard fix is. |
| Comment by Klaus Lehner [ 30/Aug/10 ] |
|
any forecast when this will be fixed? |
| Comment by Mike DeLaurentis [ 23/Aug/10 ] |
|
I'm seeing this issue also, using the 2.0 version of the driver, with tomcat 6.0.29. I get these messages: SEVERE: The web application [/vbz2-0.1] appears to have started a thread named [ObjectId-TimeFixer] but has failed to stop it. This is very likely to create a memory leak. |
| Comment by Daniel Spilker [ 04/Aug/10 ] |
|
This is not a Tomcat specific problem. It applies to all JEE application servers and OSGI environments. I found this link which describes memory leaks in JEE environments: http://www.java-community.de/archives/140-Memory-leaks-et-alii.html |
| Comment by Eliot Horowitz (Inactive) [ 31/Jul/10 ] |
|
Removing the thread locals is not an option. Can anyone point to tomcat documentation on what they're thinking/expecting? |
| Comment by Daniel Spilker [ 30/Jul/10 ] |
|
I created two more patches to get rid of two of the ThreadLocals: http://github.com/daspilker/mongo-java-driver/commit/c72945ca0518265b2db6dad92e1c63a09331cdcf and http://github.com/daspilker/mongo-java-driver/commit/bf47166013d03e5d798318eb9744b8c6586e70ff As I understand the code these ThreadLocals avoid object creation for OutMessage and BSONDecoder objects. But these objects are cheap to create. So it should not decrease throughput when not caching instances of these objects. |
| Comment by Daniel Spilker [ 30/Jul/10 ] |
|
Cool, I'm currently trying the same. I also noted a decrease in throughput, but I can live with that. |
| Comment by Eliot Horowitz (Inactive) [ 30/Jul/10 ] |
|
I got rid of the ObejctId Thread. |
| Comment by Eliot Horowitz (Inactive) [ 23/Jul/10 ] |
|
I don't these are serious. I still don't understand what tomcat is thinking - really doesn't make much sense to me at this point... |
| Comment by Matt Wright [ 23/Jul/10 ] |
|
Would just like to say that this happens on Windows as well. Its quite disconcerting to see these "severe" messages from Tomcat when reloading or stopping the webapp. Do we need to be concerned about them? It sounds like there is some significant differences in understanding amongst the comments on this issue. In addition to the ThreadLocal messages I also get this message just before them: SEVERE: The web application [/compositor] appears to have started a thread named [ObjectId-TimeFixer] but has failed to stop it. This is very likely to create a memory leak. |
| Comment by Eliot Horowitz (Inactive) [ 23/Jul/10 ] |
|
That change is bad because if you have multiple Mongo instances closing one will stop the thread which is very bad. |
| Comment by Daniel Spilker [ 23/Jul/10 ] |
|
There are shutdown hooks defined by the Servlet API, but I think it is not a good practice for a database driver to register any hooks with a Servlet engine. The driver shut provide some methods to dispose all resources used by the driver. The web application is responsible for calling such methods when it is been undeployed. E.g. the web app needs to class mongo.close() for all mongo objects which have been created by the web application. When there are further resources, like threads which are shared by several mongo objects, the driver can expose more methods which the application must call to dispose these resources. I forked the Java driver on GitHub and added a method to stop the thread which is used by ObjectId. Please have a look at http://github.com/daspilker/mongo-java-driver/commit/664383806941ad148f25fd19b428139248f2f200. My application calls mongo.close() and ObjectId.stopTimer() when it is being undeployed. This resolves the problem that the ObjectId thread keeps on running when the application is undeployed. |
| Comment by Eliot Horowitz (Inactive) [ 22/Jul/10 ] |
|
Do you know if a shutdown hook will be executed for each container? |
| Comment by Daniel Spilker [ 22/Jul/10 ] |
|
Every webapp is loaded with it's own class loader. So when you have two webapps running in one Tomcat instance all classes are loaded and initialized twice. This means that the thread started in the static initializer in ObjectId is started twice, once for each webapp. I think this behavior is mandated by the Servlet specification and is true for every Servlet container, not only for Tomcat. Disposing everything on Mongo.close() may not be a good idea, when you have multiple mongo connections in one webapp. But there should be a way to clean things up after the last connection has been closed. |
| Comment by Eliot Horowitz (Inactive) [ 22/Jul/10 ] |
|
Its a little weird though because in a normal open - you may have multiple Mongo objects, but a thread may use many. So having Mongo.close() clear thread locals seems like a really bad idea... Does tomcat guarantee that a single Thread only is used by a single app? |
| Comment by Daniel Spilker [ 22/Jul/10 ] |
|
Tomcat executes the shutdown hooks for servlet etc. This is where we are calling Mongo.close(). I would expect Mongo.close() to dispose all resources used by the driver, including clearing ThreadLocals and stopping any threads. |
| Comment by Eliot Horowitz (Inactive) [ 22/Jul/10 ] |
|
What is the hook tomcat expects to use to clean things up? |
| Comment by Daniel Spilker [ 22/Jul/10 ] |
|
We are running the MongoDB Java driver 2.0 in a webapp in Tomcat 7.0.0 beta and we are seeing the same messages as Klaus did. Additionally there is a thread which is marked as daemon, but not stopped when the webapp is undeloyed: 22.07.2010 18:47:25 org.apache.catalina.loader.WebappClassLoader clearReferencesThreads |
| Comment by Eliot Horowitz (Inactive) [ 20/Jul/10 ] |
|
Can you get a thread name for that? |
| Comment by Klaus Lehner [ 20/Jul/10 ] |
|
It also seems that there is a non-daemon thread that is not terminating when tomcat is stopped. |