Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Hibernate4 + c3p0 + Derby - Memory Leak on Tomcat stop or web application reload

I have a very simple application template which includes an embedded apache derby database through hibernate.

I have the following configuration:

    <property name="hibernate.dialect"> org.hibernate.dialect.DerbyTenSevenDialect</property>
    <property name="hibernate.connection.driver_class"> org.apache.derby.jdbc.EmbeddedDriver </property>
    <property name="hibernate.connection.username"></property>
    <property name="hibernate.connection.password"></property>
    <property name="current_session_context_class">thread</property>
    <property name="connection.pool_size">10</property>
    <property name="connection.provider_class">org.hibernate.service.jdbc.connections.internal.C3P0ConnectionProvider</property>
    <property name="hibernate.c3p0.acquire_increment">1</property>
    <property name="hibernate.c3p0.min_size">5</property>
    <property name="hibernate.c3p0.max_size">20</property>
    <property name="hibernate.c3p0.timeout">300</property>
    <property name="hibernate.c3p0.idle_test_period">3000</property>
    <property name="hibernate.c3p0.max_statements">50</property>
    <property name="hibernate.c3p0.testConnectionOnCheckout">true</property>
    <property name="hibernate.hbm2ddl.auto">update</property>
    <property name="cache.use_second_level_cache">false</property>
    <property name="cache.use_query_cache">false</property>
    <property name="cache.provider_class">org.hibernate.cache.NoCacheProvider</property>
    <property name="hibernate.show_sql">false</property>
    <property name="hibernate.format_sql">false</property>

and a the init method for the SessionFactory is:

public static void init(String hibernateConfigurationResource,String connectionUrl) {
    try {
        configuration = new Configuration();
        configuration.configure(hibernateConfigurationResource);
        if (connectionUrl == null || connectionUrl.length() == 0) {
            connectionUrl = "myDb";
        } else {
            connectionUrl += File.separator + "myDb";
        }
        File f = new File(connectionUrl);
        if (logger.isDebugEnabled()) {
            logger.debug("Using db path: " + f.getAbsolutePath());
        }
        if (!f.exists()) {
            if (logger.isDebugEnabled()) {
                logger.debug("Database does not exist: creating");
            }
            connectionUrl += ";create=true";
        }
        configuration
                .setProperty("hibernate.connection.url", "jdbc:derby:"
                    + connectionUrl);

        serviceRegistry =
            new ServiceRegistryBuilder().applySettings(configuration.getProperties()).buildServiceRegistry();
        sessionFactory = configuration.buildSessionFactory(serviceRegistry);
    } catch (Throwable ex) {
        throw new ExceptionInInitializerError(ex);
    }
}

and at the destroy phase, this method is called:

public static void destroy() throws SQLException {
    String connectionUrl = configuration
            .getProperty("hibernate.connection.url").replace(";create=true", "");
    try {
        if (logger.isDebugEnabled()) {
            logger.debug("Shutting down database: " + connectionUrl);
        }
        DriverManager.getConnection(connectionUrl + ";shutdown=true");
    } catch (SQLNonTransientConnectionException e) {
        if (logger.isDebugEnabled()) {
            logger.debug(e.getMessage());
        }
        String message = e.getMessage();
        if (!(message.startsWith("Database") && message
                .endsWith("shutdown."))) {
            throw e;
        }
    }
    try {
        Session s = sessionFactory.getCurrentSession();
        if (s.isDirty()) {
            s.flush();
        }
        s.disconnect();
        s.close();
        sessionFactory.close();
    } catch (Exception e) {
        logger.error(e);
    }

    Enumeration<Driver> drivers = DriverManager.getDrivers();
    while (drivers.hasMoreElements()) {
        Driver driver = drivers.nextElement();
        try {
            logger.info("Deregistering jdbc driver: " + driver);
            DriverManager.deregisterDriver(driver);
        } catch (SQLException e) {
            logger.warn("Error deregistering driver " + driver, e);
        }

    }
}

I noticed that the application is running fine but as soon as I stop the tomcat, I see the following messages:

INFO: Stopping service Catalina
apr 17, 2013 4:34:36 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/myWebApp-webapp] appears to have started a thread named [Timer-1] but has failed to stop it. This is very likely to create a memory leak.
apr 17, 2013 4:34:36 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/myWebApp-webapp] appears to have started a thread named [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0] but has failed to stop it. This is very likely to create a memory leak.
apr 17, 2013 4:34:36 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/myWebApp-webapp] appears to have started a thread named [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1] but has failed to stop it. This is very likely to create a memory leak.
apr 17, 2013 4:34:36 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/myWebApp-webapp] appears to have started a thread named [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2] but has failed to stop it. This is very likely to create a memory leak.
apr 17, 2013 4:34:36 PM org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks
SEVERE: The web application [/myWebApp-webapp] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@106f4e54]) and a value of type [org.apache.derby.iapi.services.context.ContextManager] (value [org.apache.derby.iapi.services.context.ContextManager@587cc9a3]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak. 
apr 17, 2013 4:34:36 PM org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks
SEVERE: The web application [/myWebApp-webapp] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@106f4e54]) and a value of type [org.apache.derby.iapi.services.context.ContextManager] (value [org.apache.derby.iapi.services.context.ContextManager@2e704a6]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak. 
apr 17, 2013 4:34:36 PM org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks
SEVERE: The web application [/myWebApp-webapp] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@106f4e54]) and a value of type [org.apache.derby.iapi.services.context.ContextManager] (value [org.apache.derby.iapi.services.context.ContextManager@36bc4735]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak. 
apr 17, 2013 4:34:36 PM org.apache.coyote.AbstractProtocolHandler stop
INFO: Stopping ProtocolHandler ["http-bio-8080"]
apr 17, 2013 4:34:36 PM org.apache.coyote.AbstractProtocolHandler stop
INFO: Stopping ProtocolHandler ["ajp-bio-8009"]

I am pretty sure that the problem is at the connection pooling level with Hibernate not being able to shut down the c3p0 connection provider properly. I tried also with mysql and the issue is still there.

I am also aware of the tomcat protection against memory leaks (that is actually producing that messages) and I am running Tomcat 7.0.39.

Moreover I don't want to move the connection pool outside the application (delegating the container).

How can I tell hibernate to shutdown everything properly and avoid those messages? What am I missing?

Thank you in advance!

EDIT:

The log on the shutdown just show:

2013-04-18 10:27:13,537 DEBUG [Thread-13] HibernateUtil  - Shutting down database: jdbc:derby:myDb
2013-04-18 10:27:13,555 DEBUG [Thread-13] HibernateUtil  - Database 'myDb' shutdown.
2013-04-18 10:27:13,656 DEBUG [Thread-13] SessionImpl  - Disconnecting session
2013-04-18 10:27:13,656 DEBUG [Thread-13] LogicalConnectionImpl  - Releasing JDBC connection
2013-04-18 10:27:13,658 DEBUG [Thread-13] SessionFactoryImpl  - HHH000031: Closing
2013-04-18 10:27:13,659 INFO  [Thread-13] HibernateUtil  - Deregistering jdbc driver: sun.jdbc.odbc.JdbcOdbcDriver@35849932
2013-04-18 10:27:13,659 INFO  [Thread-13] HibernateUtil  - Deregistering jdbc driver: org.apache.derby.jdbc.AutoloadedDriver40@7d7ff794

On the startup I have only the following line for the class AbstractPoolBackedDataSource:

2013-04-18 10:25:38,808 INFO  [Thread-2] AbstractPoolBackedDataSource  - Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@28fe617e [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@8c36e25a [ acquireIncrement -> 1, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, debugUnreturnedConnectionStackTraces -> false, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 2s05jr8u7u65au1gs0zth|25e62c36, idleConnectionTestPeriod -> 3000, initialPoolSize -> 3, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 300, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 20, maxStatements -> 50, maxStatementsPerConnection -> 0, minPoolSize -> 5, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@423e8f48 [ description -> null, driverClass -> null, factoryClassLocation -> null, identityToken -> 2s05jr8u7u65au1gs0zth|363bec9c, jdbcUrl -> jdbc:derby:myDb, properties -> {user=******, password=******} ], preferredTestQuery -> null, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> true, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, factoryClassLocation -> null, identityToken -> 2s05jr8u7u65au1gs0zth|43ba9cea, numHelperThreads -> 3 ]
like image 842
ChaSIem Avatar asked Dec 11 '22 15:12

ChaSIem


2 Answers

After doing some more research I found that closing explicitely all the connections solves the issue:

C3P0Registry.getNumPooledDataSources();

@SuppressWarnings({ "unchecked", "rawtypes" })
Iterator<Set> it = C3P0Registry.getPooledDataSources().iterator();
while (it.hasNext()) {
    try {
           dataSource = (PooledDataSource) it.next();
           dataSource.close();
    } catch (Exception e) {
           logger.error(e);
    }
}
like image 55
ChaSIem Avatar answered Jan 13 '23 05:01

ChaSIem


A more concise version of the accepted answer that did the trick for me

for (Object o : C3P0Registry.getPooledDataSources()) {
  try {
    ((PooledDataSource) o).close();
  } catch (Exception e) {
    // oh well, let tomcat do the complaing for us.
  }
}
like image 26
Gus Avatar answered Jan 13 '23 04:01

Gus