Search code examples
javaspringtomcatc3p0

warning while stopping tomcat 7 from com.mchange.v2.async.ThreadPoolAsynchronousRunner

I am working on an spring MVC project. Project is still under development and I am getting this below warning in STS and also if I deploy war into my local Tomcat 7 server.

warning on console :

ClassLoaderLeakPreventor: Stopping Thread 'Thread[C3P0PooledConnectionPoolManager[identityToken->2ryrk49cntz2wcsrr79v|40b86944]-HelperThread-#2,5,main]' of type com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread running in web app after 5000 ms 
WARN : 13:26:22.626 com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:689) - An Error forced the closing of Thread[C3P0PooledConnectionPoolManager[identityToken->2ryrk49cntz2wcsrr79v|40b86944]-HelperThread-#1,5,main]. Will attempt to reconstruct, but this might mean that something bad is happening.
java.lang.ThreadDeath
    at java.lang.Thread.stop(Thread.java:758)
    at se.jiderhamn.classloader.leak.prevention.ClassLoaderLeakPreventor.stopThreads(ClassLoaderLeakPreventor.java:732)
    at se.jiderhamn.classloader.leak.prevention.ClassLoaderLeakPreventor.contextDestroyed(ClassLoaderLeakPreventor.java:397)
    at org.apache.catalina.core.StandardContext.listenerStop(StandardContext.java:4741)
    at org.apache.catalina.core.StandardContext$4.run(StandardContext.java:5450)
    at java.lang.Thread.run(Thread.java:662)
    at org.apache.catalina.core.StandardContext.stopInternal(StandardContext.java:5459)
    at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:225)
    at org.apache.catalina.core.ContainerBase.stopInternal(ContainerBase.java:1072)
    at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:225)
    at org.apache.catalina.core.ContainerBase.stopInternal(ContainerBase.java:1072)
    at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:225)
    at org.apache.catalina.core.StandardService.stopInternal(StandardService.java:502)
    at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:225)
    at org.apache.catalina.core.StandardServer.stopInternal(StandardServer.java:748)
    at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:225)
    at org.apache.catalina.startup.Catalina.stop(Catalina.java:693)
    at org.apache.catalina.startup.Catalina.start(Catalina.java:654)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:303)
    at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:431)

I am not able to trace why this happening. On console I can see this warning continuously printing and tomcat server is in stopping mode more than 10-12 mins.

We have used class loader leak protection by adding following dependency in pom.xm

<dependency>
   <groupId>se.jiderhamn</groupId>
   <artifactId>classloader-leak-prevention</artifactId>
    <version>1.8.0</version>
</dependency>

Also c3p0 dependency 

<dependency>
    <groupId>com.mchange</groupId>
    <artifactId>c3p0</artifactId>
    <version>0.9.2</version>
</dependency>

Why it is saying something bad is happening in warning? Is this a serious issue? How can I stop this?

Solution

  • TL; DR: Upgrade to c3p0 0.9.5.1, then set privilegeSpawnedThreads to true and contextClassLoaderSource to library. Make sure that any web-app that creates a c3p0 pool internally closes it on web-app undeploy.

    Docs: See c3p0 docs on this issue, here and here

    Long version:

    Tomcat segregates web-app deployments into dedicated ClassLoaders. On hot redeploy, your web app's code is reloaded into a new ClassLoader, which is how your code changes become visible without restarting the whole JVM.

    But old ClassLoaders cannot be garbage collected if Threads refer to objects of classes loaded with those old ClassLoaders.

    c3p0 starts up a bunch of Threads every time a PooledDataSource is initialized (when the first Connection is requested). If a web app loaded class provokes the initialization, those Threads may start loading classes with the web-app specific ClassLoader. If those Threads remain alive upon hot-redeploy, they will prevent the garbage collection of the obsoleted ClassLoader and cause a memory leak. (Both the old ClassLoader and the zombie Threads will be unhelpfully retained.) That is the bad thing that is happening in your case. Eventually, after some number of redeploys, you'll see OutOfMemoryErrors and things will turn flaky.

    Fortunately, it is not hard to deal with this. A few suggestions:

    No matter what, be sure to scope your Connection pool consistently.

    • If the Connection pool is going to be entirely private to a web app, meaning that the pool will be started within a web-app, will be used only by that web-app, and c3p0's libraries will live in the web-app's WEB-INF/lib directory, then be sure that your web app also calls close() on the pool prior to any undeploy, which will cause the pool's Threads to terminate. The best way to accomplish that is with a ServletContextListener. Start up your pool in contextInitialized(...), and close() it in contextDestroyed(...).
    • If the Connection pool is going to be an application server resource, perhaps set up in Tomcat's config files rather than instantiated in code, then make sure that c3p0's libraries (both jar files) are placed where they will be loaded by a shared ClassLoader. Most commonly this is the lib directory of the top-level Tomcat installation.

    In either case, you'll want to upgrade to c3p0-0.9.5 or higher (the current production version is 0.9.5.1), then set the following c3p0 config parameters to take the randomness out of what ClassLoader c3p0-internal Threads come to reference:

    Hope this helps!